Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ActiveJob extension for preserving logs #733

Closed
wants to merge 2 commits into from
Closed
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
1 change: 1 addition & 0 deletions lib/good_job.rb
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
require "good_job/adapter"
require "active_job/queue_adapters/good_job_adapter"
require "good_job/active_job_extensions/concurrency"
require "good_job/active_job_extensions/logging"

require "good_job/assignable_connection"
require "good_job/cleanup_tracker"
Expand Down
38 changes: 38 additions & 0 deletions lib/good_job/active_job_extensions/logging.rb
Original file line number Diff line number Diff line change
@@ -0,0 +1,38 @@
# frozen_string_literal: true
module GoodJob
module ActiveJobExtensions
module Logging
extend ActiveSupport::Concern

included do
around_perform do |job, block|
original_logger = job.logger
job.logger = ActiveSupport::TaggedLogging.new(ActiveSupport::Logger.new(LogDevice.new(job)).extend(ActiveSupport::Logger.broadcast(original_logger)))
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@bensheldon , the around_perform hook above makes sense to me but what do L10 and L11 do exactly please ?

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is creating a new logger that outputs to the custom LogDevice, and then teeing the output via broadcast so that the output still goes to the old logger too.

I could probably break this up into multiple lines. e.g.

custom_logger = ActiveSupport::TaggedLogging.new(ActiveSupport::Logger.new(LogDevice.new(job))
custom.logger.extend(ActiveSupport::Logger.broadcast(original_logger))

ActiveSupport::TaggedLogging.new(ActiveSupport::Logger.new(LogDevice.new(job)).extend(ActiveSupport::Logger.broadcast(original_logger)))

block.call
ensure
job.logger = original_logger
end
end

class LogDevice
cattr_accessor :logs, default: Concurrent::Array.new
Copy link
Author

@NeimadTL NeimadTL Nov 1, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@bensheldon is the c in cattr_accessor to indicate that this is a class attribute

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, it's a class attribute. By living on the class it becomes a singleton that can be access globally.


def initialize(job)
@job = job
end

def write(message)
self.class.logs << [@job.provider_job_id, message.strip]
end

def close
Copy link
Author

@NeimadTL NeimadTL Nov 1, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think #close and #reopen are overrode method but I might be wrong here. Are those methods mandatory or you think we'll be using them in the future ?

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm trying to match the interface of Ruby's LogDevice:

https://github.com/ruby/ruby/blob/9001e53e68d282493f513ed67824e4014fd01d57/lib/logger/log_device.rb

That said, I wonder if it would be better to inherit from LogDevice to be clear that I'm trying to match/override the interface, rather than just be an implicit duck-type.

nil
end

def reopen(_log = nil)
nil
end
end
end
end
end
37 changes: 37 additions & 0 deletions spec/lib/good_job/active_job_extensions/logging_spec.rb
Original file line number Diff line number Diff line change
@@ -0,0 +1,37 @@
# spec/lib/good_job/active_job_extensions/logging_spec.rb

# frozen_string_literal: true
require 'rails_helper'

RSpec.describe GoodJob::ActiveJobExtensions::Logging do
before do
# freeze_time
ActiveJob::Base.queue_adapter = GoodJob::Adapter.new(execution_mode: :external)

stub_const 'TestJob', (Class.new(ActiveJob::Base) do
include GoodJob::ActiveJobExtensions::Logging

def perform
logger.info "Hello, world!"
logger.debug "Debug level!"
logger.tagged("TAG") { logger.info "Tagged!" }
end
end)
end

# very naive test case, please modify based on implementation
describe '.logs' do
it 'stores the logs from the job in a tuple of execution ID and log' do
active_job = TestJob.perform_later
GoodJob.perform_inline

job_log = described_class::LogDevice.logs
# I expect this tuple would be replaced with a better object eventually, but that can be deferred to later checkpoints.
expect(job_log).to eq([
[active_job.provider_job_id, 'Hello, world!'],
[active_job.provider_job_id, 'Debug level!'],
[active_job.provider_job_id, '[TAG] Tagged!'],
])
end
end
end