Repository navigation
Log GoodJob workers as JSON, and each GoodJob error once - #20
Merged
Merged
Conversation
LogStruct turned itself on in Puma, Rails servers and Sidekiq, but not in `good_job start` workers, which kept writing Rails' plain text logs. Treat GoodJob's executable as a server process: it sets GoodJob::CLI.within_exe before it loads the app. GoodJob's executable also adds a plain text STDOUT logger to its log subscriber unless GoodJob.logger already writes to STDOUT, which it can't tell for LogStruct's logger, so every GoodJob line would be written twice. Turn that off when LogStruct replaces GoodJob's logger.
GoodJob applies config.good_job (logger, on_thread_error) in an after_initialize block. An app that sets on_thread_error there, as GoodJob's README does to report thread errors to an error tracker, replaced LogStruct's handler, so thread errors were reported but no longer logged. LogStruct now wraps the handler again after initialization.
GoodJob calls on_thread_error for every error its job and timer tasks raise, and its own log subscriber then logs the same error as "GoodJob error: ..." text with the whole backtrace in the message (over 10KB). LogStruct's thread error handler already logs each one as a structured line, so GoodJob's finished_job_task and finished_timer_task lines are turned off when that handler is in place.
The thread error handler passes a LogStruct::Log::GoodJob::Error entry to GoodJob.logger, and LogStruct's GoodJob logger wrapped every message in a Log::GoodJob::Log, whose message must be a String. Every thread error raised a TypeError (outside production) or logged a Sorbet error instead of the thread error. The logger now logs LogStruct entries and Hashes as they are, and the thread error line has level error. The tests stubbed the logger, so they never ran this path.
GoodJob::LogSubscriber also logs the notifier's and systemd's thread errors as text with the whole backtrace. The notifier only calls on_thread_error after repeated connection errors, so these lines are still logged, with the error class and message only.
LogStruct logged thread errors by replacing GoodJob.on_thread_error with a handler that called the app's. In a Rails app, GoodJob's engine applies config.good_job.on_thread_error in an after_initialize block that runs after LogStruct's, so it replaced LogStruct's handler and thread errors were reported but not logged. The test stubbed after_initialize, so it never ran the real order. LogStruct now prepends GoodJob._on_thread_error, which every GoodJob component calls with its thread errors: it logs the structured line, then calls whatever handler the app set, whenever it was set.
…doesn't send It handled enqueue, start, finish, error and schedule events, but GoodJob's events are enqueue_job, perform_job and the scheduler, notifier and cron events, so none of its methods ever ran. GoodJob's jobs are already logged by the ActiveJob integration, so subscribing to GoodJob's real events would log every job twice. The docs now say what the integration logs: GoodJob's own messages and its thread errors.
…dErrors GoodJob passes every unhandled job exception to on_thread_error, after the ActiveJob integration has already logged it with the job's ID and class, so each failed job was logged as two job error lines. The ActiveJob integration now records the exceptions it logs (LogStruct::LoggedErrors, which holds them weakly), and the thread error line skips them. The app's handler still gets every error. GoodJob's notifier passes every error except connection errors to on_thread_error straight away, and systemd watchdog errors always, so GoodJob's own lines for those are off too. The notifier's line for connection errors is kept, since it passes those on only once they repeat. The finished_timer_task override is gone: GoodJob instruments that event without the .good_job suffix, so its log subscriber never receives it. GoodJob passes any Exception that its handled_exceptions setting lets through, and ActiveJob's perform_now lets any Exception through. Both handlers' signatures only accepted StandardError, so outside production a NotImplementedError raised a TypeError and the app's handler was skipped. Log::Error's error_class is now any Exception class.
The GoodJob logger read the running job from Thread.current[:good_job_execution], which GoodJob never sets, so its lines never had the job's ID, class or queue. It now reads GoodJob::CurrentThread.job (GoodJob 4) or .execution (GoodJob 3). The tests set that thread variable themselves, so they passed.
GoodJob::Enqueue, Start, Finish and Schedule were only built by the removed GoodJob log subscriber. GoodJob's jobs are logged by the ActiveJob integration, whose lines have the same src and evt. The Terraform provider's catalog now lists only error and log for GoodJob, and the docs no longer describe GoodJob lifecycle events. The docs say the integration needs GoodJob 3.0 or later (GoodJob._on_thread_error).
|
Warning Review limit reached
This review includes 28 billable files and costs up to $7.00.
Reviews can continue after your included limit without a manual trigger. An admin must approve usage-based billing. Or wait 37 minutes for your next included review. View limit details
Comment |
This was referenced Oct 17, 2026
Merged
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fifth of twelve stacked PRs for 0.2.0.
What this fixes
good_job startworkers wrote plain text. LogStruct now turns itself on in GoodJob's executable, like Puma and Sidekiq, and stops GoodJob adding a second, plain text STDOUT logger beside it.config.good_job.on_thread_errorafter LogStruct's setup, so it replaced LogStruct's handler. LogStruct now prependsGoodJob._on_thread_error, which every GoodJob component calls: it logs a structured error line, then calls whatever handler the app set.TypeError. LogStruct's GoodJob logger only took Strings. It now logs LogStruct entries and Hashes as they are.on_thread_error, so its own lines for them are off. The one exception is the notifier's connection errors, which GoodJob passes on only once they repeat: its line for those stays, without the backtrace.on_thread_error, after the ActiveJob integration has logged it with the job's ID and class. The ActiveJob integration now marks the exceptions it logs (LogStruct::LoggedErrors, a weak map), and the thread error handler skips them.StandardErrors raised aTypeErrorin the handler. GoodJob passes anyExceptionthat itshandled_exceptionssetting lets through, for example a job'sNotImplementedError. The handlers, the ActiveJob error line andLog.from_exceptionnow take anyException, anderror_classonLog::ErrorisT.class_of(Exception).GoodJob::CurrentThreadwhile a job runs.LogStruct::Integrations::GoodJob::LogSubscriber. It listened for events GoodJob doesn't send (enqueue,start,finish,error,schedule), so it never ran. GoodJob's jobs are logged by the ActiveJob integration, so subscribing to GoodJob's real events would log each job twice.LogStruct::Log::GoodJob::Enqueue,Start,FinishandSchedulelog types, which only the subscriber built. GoodJob lines areloganderrorlines. The schema, the generated docs, the Terraform provider catalog check and the integration docs (now "GoodJob 3.0 or later") match.Breaking: code that referred to the removed classes or to the four GoodJob event types. Code that read
error_classas aStandardErrorsubclass getsT.class_of(Exception).Testing
The thread-error test runs the real order (the app sets its handler after LogStruct's setup) and fails on the old code; so do the tests for a failed job's exception (one line), a
NotImplementedErrorand theCurrentThreadfields. Also checked with real GoodJob 4.19 in a Rails app booted in production mode: one line each for a thread error, a failed job and aNotImplementedError. Sorbet and the unit suite (294 tests) pass at this branch's tip.Stack for 0.2.0, merged in order: #16 → #17 → #18 → #19 → #20 → #21 → #22 → #23 → #24 → #25 → #26 → #27