Question: Could this work for DelayedJob as well?

[roidrage]

Question: Could this work for DelayedJob as well?

[rhomeister]

Here is my quick and dirty first approach. Works like a charm. Put this in config/initializers. Note that this is currently LogStash specific.

require 'delayed_job'

class LogstashPlugin < Delayed::Plugin

  def self.logstash_logger
    @logger ||= create_logger
  end

  def self.create_logger
    return NullLogger.new unless Rails.configuration.logstash.try(:host)

    LogStashLogger.new(type: Rails.configuration.logstash.try(:type),
                       host: Rails.configuration.logstash.try(:host),
                       port: Rails.configuration.logstash.try(:port))
  end

  class NullLogger
    def info(*args)
    end
  end

  callbacks do |lifecycle|
    lifecycle.around(:invoke_job) do |job, *args, &block|
      start = Time.now
      block.call(job, *args)
      runtime = Time.now - start
      queued = start - job.created_at if job.created_at
      logstash_logger.info(
        event: 'delayed_job_completed',
        id: job.id,
        priority: job.priority,
        queue: job.queue,
        runtime: runtime,
        name: job.name,
        created_at: job.created_at,
        started_at: start,
        queued: queued)
    end
  end
end

Delayed::Worker.plugins << LogstashPlugin

[janraasch]

Hi @caljess599, thank you for replying. Maybe someone else may find this useful. For me this is a nice blast from the past 😅😁.

[shunwen]

@rhomeister Looks like you're using the logstash formatter? You could write your own formatter to format log messages in the way you want, see https://github.com/roidrage/lograge/blob/master/lib%2Flograge%2Fformatters%2Flogstash.rb for example.

[pxlpnk]

I don't have any deeper knowledge on DelayedJob. How does it work?
Is it using the rails logging system?

[benlovell]

It loads the rails environment, so would use the rails logging infrastructure.

[pxlpnk]

In this case it should be possible with a bit of fiddeling making a custom formatter that differentiates (no idea how though) between AR and DJ logs and could split the format them.

[rhomeister]

Hi guys,

Thanks for your input. As soon as I have some time, I'll see if I can make
a proof of concept.

On 18 February 2015 at 16:00, Andreas Tiefenthaler <[email protected]

wrote:

In this case it should be possible with a bit of fiddeling making a custom
formatter that differentiates (no idea how though) between AR and DJ logs
and could split the format them.

—
Reply to this email directly or view it on GitHub
#114 (comment).

[pxlpnk]

👍 Curious what you come up with

[janraasch]

We use DJ together with lograge in our rails apps. Not sure if this is related, but for some reason we have duplicate lines in our logs like

[Worker(host:some_hash pid:some_pid)] Job MyJobName (id=1) COMPLETED after 2 
2013-02-11T15:00:00+0000: [Worker(host:some_hash pid:some_pid)] Job MyJobName (id=1) COMPLETED after 3

i.e. one line with a timestamp in front and one without.

[pxlpnk]

@janraasch could you share some code that would allow me to reproduce your setup? You can use a fork of this repo to do so: https://github.com/pxlpnk/lograge-rails-apps
You most likely have to adjust lograge in the Gemfile for your setup.

[janraasch]

@pxlpnk thank you for caring. It's a pretty huge app though. The lograge, rails and delayed_job specifics are:

Gemfile:

source 'https://rubygems.org'
ruby '2.0.0'

gem 'rails',                     '~> 4.0.0'
gem 'lograge',                   '~> 0.3.1'
gem 'delayed_job_active_record'
gem 'delayed_job_web'

and the application.rb part is

  config.lograge.enabled = true
  config.lograge.custom_options = lambda do |event|
    params = event.payload[:params].reject do |k|
      %w(controller action).include? k
    end

    { 'params' => params }
  end

Let me know, if that is enough info. If not, I will try to make some time and fork https://github.com/pxlpnk/lograge-rails-apps into a working example.

[pxlpnk]

Thank you, I try to craft a setup with this in the next few days, if I need more I just ping you (:

[benlovell]

@pxlpnk did you ever get anywhere with this?

[pxlpnk]

I was playing around with it but didn't get anywhere yet.

[caljess599]

@janraasch Not that you still need to know this 5 years later, but the reason you see duplicate lines is because the gem logs everything to STDOUT already, and that output cannot be directed into a logger (at least AFAIK). Therefore, if you specify a logger in your config, e.g., Delayed::Worker.logger = Logger.new(STDOUT), you end up doubling the output to STDOUT. (The lines look slightly different because Logger has a default formatting wrapper.)