Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion INTEGRATIONS.md
Original file line number Diff line number Diff line change
Expand Up @@ -113,7 +113,7 @@

- GoodJob:
- Log type: `lib/log_struct/log/good_job.rb`
- Integration: `lib/log_struct/integrations/good_job.rb` (+ `logger.rb`, `log_subscriber.rb`)
- Integration: `lib/log_struct/integrations/good_job.rb` (+ `logger.rb`)
- Toggle: `enable_goodjob`
- SQL (ActiveRecord):
- Log type: `lib/log_struct/log/sql.rb`
Expand Down
4 changes: 2 additions & 2 deletions docs/lib/integration-helpers.ts
Original file line number Diff line number Diff line change
Expand Up @@ -88,7 +88,7 @@ export function getLogTypeInfo(logType: LogType): {
return {
title: 'GoodJob',
description:
'The GoodJob integration logs job lifecycle events (enqueue, start, finish, error) with execution context and performance metrics.',
"The GoodJob integration logs GoodJob's own messages and its thread errors as structured lines (GoodJob 3.0 or later). GoodJob's jobs are logged by the ActiveJob integration.",
};

case LogType.SQL:
Expand Down Expand Up @@ -150,7 +150,7 @@ export function getEventsForLogType(logType: LogType): Event[] {
case LogType.CARRIERWAVE:
return [Event.Upload, Event.Delete];
case LogType.GOODJOB:
return [Event.Enqueue, Event.Start, Event.Finish, Event.Error, Event.Log];
return [Event.Error, Event.Log];
case LogType.SQL:
return [Event.Database];
case LogType.ACTIVEMODELSERIALIZERS:
Expand Down
11 changes: 1 addition & 10 deletions docs/lib/log-generation/log-generator.ts
Original file line number Diff line number Diff line change
Expand Up @@ -171,16 +171,7 @@ export class LogGenerator extends RandomDataGenerator {
}

case LogType.GOODJOB: {
switch (
evt ??
this.sample([Event.Enqueue, Event.Start, Event.Finish, Event.Error, Event.Log])
) {
case Event.Enqueue:
return GoodJob.GoodJobEnqueue.random(this).serialize();
case Event.Start:
return GoodJob.GoodJobStart.random(this).serialize();
case Event.Finish:
return GoodJob.GoodJobFinish.random(this).serialize();
switch (evt ?? this.sample([Event.Error, Event.Log])) {
case Event.Error:
return GoodJob.GoodJobError.random(this).serialize();
default:
Expand Down
11 changes: 5 additions & 6 deletions docs/lib/log-structure-descriptions.ts
Original file line number Diff line number Diff line change
Expand Up @@ -10,11 +10,10 @@ export const LOG_STRUCTURE_DESCRIPTIONS: Record<string, string> = {
Delivered: 'ActionMailer callback emitted after a message is delivered',
Delivery: 'ActionMailer event capturing when a mailer sends a message',
ActiveJob: 'For background job execution',
Enqueue: 'Background job enqueued event (ActiveJob or GoodJob scheduling a job for execution)',
Finish: 'Background job completion event indicating success (ActiveJob/GoodJob)',
Schedule:
'Deferred background job scheduling event (ActiveJob or GoodJob scheduling with a run_at time)',
Start: 'Lifecycle start event for jobs or services (ActiveJob, GoodJob, or Puma boot)',
Enqueue: 'Background job enqueued event (ActiveJob scheduling a job for execution)',
Finish: 'Background job completion event indicating success (ActiveJob)',
Schedule: 'Deferred background job scheduling event (ActiveJob scheduling with a run_at time)',
Start: 'Lifecycle start event for jobs or services (ActiveJob or Puma boot)',
ActiveStorage: 'For file storage operations',
Delete: 'Deletion of a persisted attachment (ActiveStorage, CarrierWave, or Shrine)',
Download: 'File download event (ActiveStorage, CarrierWave, or Shrine)',
Expand All @@ -31,7 +30,7 @@ export const LOG_STRUCTURE_DESCRIPTIONS: Record<string, string> = {
'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 background job lifecycle events',
GoodJob: "For GoodJob's own log lines and thread errors",
Log: 'Structured GoodJob log output captured from the worker process',
SQL: 'For ActiveRecord SQL query events and performance metrics',
ActiveModelSerializers:
Expand Down
1 change: 1 addition & 0 deletions lib/log_struct.rb
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
require "log_struct/enums"
require "log_struct/configuration"
require "log_struct/formatter"
require "log_struct/logged_errors"
require "log_struct/railtie"
require "log_struct/concerns/error_handling"
require "log_struct/concerns/configuration"
Expand Down
7 changes: 7 additions & 0 deletions lib/log_struct/concerns/configuration.rb
Original file line number Diff line number Diff line change
Expand Up @@ -156,6 +156,7 @@ def server_process?
return true if defined?(::Falcon::Server)
return true if defined?(::Rails::Server)
return true if sidekiq_server?
return true if good_job_cli?

false
end
Expand All @@ -176,6 +177,12 @@ def sidekiq_server?
!!(defined?(::Sidekiq) && ::Sidekiq.respond_to?(:server?) && ::Sidekiq.server?)
end

# GoodJob's executable (`good_job start`) sets within_exe before it loads the app
sig { returns(T::Boolean) }
def good_job_cli?
!!(defined?(::GoodJob::CLI) && ::GoodJob::CLI.respond_to?(:within_exe?) && ::GoodJob::CLI.within_exe?)
end

sig { returns(T::Boolean) }
def logstruct_server_mode?
::LogStruct.server_mode?
Expand Down
5 changes: 4 additions & 1 deletion lib/log_struct/integrations/active_job/log_subscriber.rb
Original file line number Diff line number Diff line change
Expand Up @@ -89,14 +89,17 @@ def build_base_fields(job)
)
end

sig { params(exception: StandardError, job: ::ActiveJob::Base, _event: ::ActiveSupport::Notifications::Event).void }
# perform_now lets any Exception through, not only StandardErrors
sig { params(exception: Exception, job: ::ActiveJob::Base, _event: ::ActiveSupport::Notifications::Event).void }
def log_exception(exception, job, _event)
base_fields = build_base_fields(job)
job_context = base_fields.to_kwargs

log_data = Log.from_exception(Source::Job, exception, job_context)

logger.error(log_data)
# So a backend that reports the same exception (GoodJob's on_thread_error) doesn't log it again
LogStruct::LoggedErrors.mark(exception)
end

sig { returns(T.untyped) }
Expand Down
149 changes: 104 additions & 45 deletions lib/log_struct/integrations/good_job.rb
Original file line number Diff line number Diff line change
Expand Up @@ -8,29 +8,17 @@
end

require_relative "good_job/logger" if defined?(::GoodJob)
require_relative "good_job/log_subscriber" if defined?(::GoodJob)

module LogStruct
module Integrations
# GoodJob integration for structured logging
#
# GoodJob is a PostgreSQL-based ActiveJob backend that provides reliable,
# scalable job processing for Rails applications. This integration provides
# structured logging for all GoodJob operations.
# GoodJob is a PostgreSQL-based ActiveJob backend. Its jobs are logged by the ActiveJob
# integration (enqueued, started, finished, failed), so this integration covers GoodJob itself:
#
# ## Features:
# - Structured logging for job execution lifecycle
# - Error tracking and retry logging
# - Performance metrics and timing data
# - Database operation logging
# - Thread and process tracking
# - Custom GoodJob logger with LogStruct formatting
#
# ## Integration Points:
# - Replaces GoodJob.logger with LogStruct-compatible logger
# - Subscribes to GoodJob's ActiveSupport notifications
# - Captures job execution events, errors, and performance metrics
# - Logs database operations and connection information
# - Replaces GoodJob.logger with a LogStruct logger, so GoodJob's own messages are JSON lines
# - Logs each thread error as a structured error line, then calls the app's `on_thread_error`
# - Stops GoodJob's own log subscriber logging those errors again with the whole backtrace
#
# ## Configuration:
# The integration is automatically enabled when GoodJob is detected and
Expand All @@ -45,8 +33,7 @@ module GoodJob

# Set up GoodJob structured logging
#
# This method configures GoodJob to use LogStruct's structured logging
# by replacing the default logger and subscribing to job events.
# This method replaces GoodJob's logger and logs its thread errors as structured lines.
#
# @param config [LogStruct::Configuration] The LogStruct configuration
# @return [Boolean, nil] Returns true if setup was successful, nil if skipped
Expand All @@ -59,13 +46,55 @@ def self.setup(config)
# Replace GoodJob's logger with our structured logger
configure_logger

# Subscribe to GoodJob's ActiveSupport notifications
subscribe_to_notifications
compact_error_lines

true
end

@thread_error_handler = T.let(nil, T.nilable(T.proc.params(exception: StandardError).void))
# GoodJob::LogSubscriber logs errors as text with the whole backtrace in the message (over 10KB).
# GoodJob passes every error its job tasks raise, every systemd watchdog error and every notifier
# error except connection errors to `on_thread_error`, which LogThreadErrors logs as a structured
# line, so GoodJob's own lines for those are off. The notifier passes connection errors on only
# once they repeat, so its line for them is kept, without the backtrace.
module CompactErrorLines
extend T::Sig
extend T::Helpers

requires_ancestor { ::GoodJob::LogSubscriber }

sig { params(_event: T.untyped).void }
def finished_job_task(_event)
end

sig { params(event: T.untyped).void }
def notifier_notify_error(event)
exception = event.payload[:error]
return unless exception
return unless LogStruct::Integrations::GoodJob.notifier_connection_error?(exception)

error { "Notifier errored: #{exception.class}: #{exception}" }
end

sig { params(_event: T.untyped).void }
def systemd_watchdog_error(_event)
end
end

# Logs each thread error as a structured line, then calls the handler the app set as
# `on_thread_error` (GoodJob's README sets one to report errors to an error tracker). Every
# GoodJob component passes its thread errors to `GoodJob._on_thread_error`, so this works
# whenever the app sets its handler: GoodJob's engine applies config.good_job.on_thread_error
# after LogStruct's setup. GoodJob passes any Exception its handled_exceptions setting lets
# through, not only StandardErrors.
module LogThreadErrors
extend T::Sig

sig { params(exception: Exception).void }
def _on_thread_error(exception)
LogStruct::Integrations::GoodJob.log_thread_error(exception)
super
end
end

# Configure GoodJob to use LogStruct's structured logger
sig { void }
Expand All @@ -78,40 +107,70 @@ def self.configure_logger
# Replace GoodJob.logger with our structured logger if GoodJob is available
if goodjob_module.respond_to?(:logger=)
goodjob_module.logger = LogStruct::Integrations::GoodJob::Logger.new("GoodJob")
end

# Log thread errors, after calling the handler the app set (GoodJob's README sets one
# to report them to an error tracker). Setting up again keeps the one handler.
if goodjob_module.respond_to?(:on_thread_error=)
app_handler = goodjob_module.on_thread_error
return if app_handler&.equal?(@thread_error_handler)

@thread_error_handler = ->(exception) do
app_handler&.call(exception)
log_entry = LogStruct::Log::GoodJob::Error.new(
error_class: exception.class.name,
error_message: exception.message,
backtrace: exception.backtrace,
process_id: ::Process.pid,
thread_id: Thread.current.object_id.to_s(36)
)
goodjob_module.logger.error(log_entry)
# GoodJob's executable adds a plain text STDOUT logger unless GoodJob.logger already writes
# to STDOUT, which it can't tell for this logger
if defined?(::GoodJob::CLI) && ::GoodJob::CLI.respond_to?(:log_to_stdout=)
::GoodJob::CLI.log_to_stdout = false
end
goodjob_module.on_thread_error = @thread_error_handler
end

configure_thread_error_handler
end

# Subscribe to GoodJob's ActiveSupport notifications
sig { void }
def self.subscribe_to_notifications
def self.configure_thread_error_handler
return unless defined?(::GoodJob)

# Subscribe to our custom log subscriber for GoodJob events
LogStruct::Integrations::GoodJob::LogSubscriber.attach_to :good_job
# Not GoodJob, which here is this module
goodjob_singleton = ::GoodJob.singleton_class
return unless goodjob_singleton.method_defined?(:_on_thread_error)

goodjob_singleton.prepend(LogThreadErrors) unless goodjob_singleton.ancestors.include?(LogThreadErrors)
end

# A failed job's exception was already logged by the ActiveJob integration, with the job's
# ID and class, so it isn't logged again here
sig { params(exception: Exception).void }
def self.log_thread_error(exception)
return if LogStruct::LoggedErrors.logged?(exception)

::GoodJob.logger.error(
LogStruct::Log::GoodJob::Error.new(
error_class: exception.class.name || exception.class.to_s,
error_message: exception.message,
backtrace: exception.backtrace,
level: LogStruct::Level::Error,
process_id: ::Process.pid,
thread_id: Thread.current.object_id.to_s(36)
)
)
end

# The errors GoodJob's notifier holds back until they repeat (GoodJob::Notifier::CONNECTION_ERRORS)
sig { params(exception: Exception).returns(T::Boolean) }
def self.notifier_connection_error?(exception)
return true unless defined?(::GoodJob::Notifier::CONNECTION_ERRORS)

::GoodJob::Notifier::CONNECTION_ERRORS.any? do |error_name|
error_class = error_name.safe_constantize
error_class.is_a?(Class) && exception.is_a?(error_class)
end
end

# Only when LogThreadErrors logs thread errors instead
sig { void }
def self.compact_error_lines
return unless defined?(::GoodJob::LogSubscriber)
return unless ::GoodJob.singleton_class.ancestors.include?(LogThreadErrors)

log_subscriber = ::GoodJob::LogSubscriber
log_subscriber.prepend(CompactErrorLines) unless log_subscriber.ancestors.include?(CompactErrorLines)
end

private_class_method :configure_logger
private_class_method :subscribe_to_notifications
private_class_method :compact_error_lines
private_class_method :configure_thread_error_handler
end
end
end
Loading