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

[help wanted]: Preserve job logs #710

Open
bensheldon opened this issue Sep 10, 2022 · 2 comments
Open

[help wanted]: Preserve job logs #710

bensheldon opened this issue Sep 10, 2022 · 2 comments
Labels
help wanted Extra attention is needed

Comments

@bensheldon
Copy link
Owner

Preserving logs during job execution has been requested in the past.

I wanted to sketch out what this feature might look like, with the hope that someone else would implement it. I've broken it down by checkpoint because I don't want to review a huge PR all at once, but rather build up the functionality so it meets my standards for quality and maintainability. I'm happy to zoom pair on it too if you drive. I'm open to change too.

The big picture

Have an ActiveJob Extension that stores logs in the database for later review.

  • Logs will be stored in their own table
  • A single execution can have multiple log records. Ideally it would flush a buffer to the database at some interval. So more than a single log record, but not so many that each log or line goes to its own record.
  • Logs should be displayable in the dashboard. And ideally be inspectable while the job is running.
  • The intention is to improve troubleshooting/debugging. Not for compliance or as a replacement for a true log drain.

Checkpoint 1

Goal: A ruby harness that tees job logs to a buffer object.

  • There exists an includeable concern that (can) contains all of the behavior to be mixed into a job class.
  • When a job runs, the existing ActiveJob logger is teed into a new in-memory buffer instance. The buffer will need to be threadsafe (queue object?), but would be nice if it can be accessed globally (eg a globally accessible object that has internal name-spacing for individual executions)
  • At the end of a run, the buffer instance can be inspected to see it contains all the logs.
  • Nice to have: allow a lower level log level (eg debug) just for the logs being retained.

Checkpoint 2

Goal: Drain logs to the database in a database-connection-efficient manner.

  • Exists an object that creates a Background thread (concurrent future) that waits on the buffer object. Can look like the Notifier.
  • Unlike the Notifier, the thread doesn't need to check out a dedicated DB connection.
  • In the thread, it should wait on the buffer, then do an efficient insert to drain the buffer, sleep a configurable amount of time, then repeat.
  • At most, writing logs should use 1 database connection per process.
  • Logs should be cleaned up automatically, just like old job records.

Checkpoint 3

Goal: surface logs in the dashboard

  • However you want, using Bootstrap and existing dashboard components.
  • Nice to have: Poll for live log updates.
@bensheldon bensheldon added the help wanted Extra attention is needed label Sep 10, 2022
@bensheldon bensheldon moved this to Inbox in GoodJob Backlog v2 Sep 10, 2022
@bensheldon
Copy link
Owner Author

Here's a simple/naive test case for Checkpoint 1:

# 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
    ActiveJob::Base.queue_adapter = GoodJob::Adapter.new(execution_mode: :external)

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

      def perform
        logger.info "Hello, world!"
        logger.debug "Debug level!"
      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.logs
      
      # I expect this tuple would be replaced with a better object eventually, but that can be deferred to later checkpoints.
      expect(job_log).eq [[active_job.provider_job_id, 'Hello, world!', 'Debug level!']]
    end
  end
end

@MarcusRiemer
Copy link

Would you be open to a simpler system as "step 0" (or maybe a different issue) that captures a single result? From a UI perspective I would imagine something similar to the way errors are displayed right now, but obviously with Result instead of Error:

image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
help wanted Extra attention is needed
Projects
Status: Inbox
Development

No branches or pull requests

2 participants