Performance degraded when attaching two loggers to Logglier

[braindeaf]

We've had some success with Logglier and Logstasher, where we've been able to take a logstash formatted representation of our production.log and push them to Loggly by extending our LogStasher.logger with Logglier. However, when we add a second logger (in our case an event log which is currently only written to by an ActiveSupport::Notifications subscriber (which is fed from DelayedJob::Worker hooks)) we find that the performance on our Delayed Job slows significantly. Given our Delayed Job queue has far less jobs than our production.log has external hits this is unexpected. Are there any immediate problems you can see when it comes to using Logglier with more than one logger, or with ActiveSupport::Notfications?

Here's how we hook it all up currently.

Core.event_logger = Logger.new("#{Rails.root}/log/event.log")
# http://www.rubydoc.info/docs/rails/4.1.7/ActiveSupport/Logger.broadcast
def Core.broadcast(logger) # :nodoc:
  Module.new do
    define_method(:add) do |*args, &block|
      logger.add(*args, &block)
      super(*args, &block)
    end

    define_method(:<<) do |x|
      logger << x
      super(x)
    end

    define_method(:close) do
      logger.close
      super()
    end

    define_method(:progname=) do |name|
      logger.progname = name
      super(name)
    end

    define_method(:formatter=) do |formatter|
      logger.formatter = formatter
      super(formatter)
    end

    define_method(:level=) do |level|
      logger.level = level
      super(level)
    end
  end
end

{
  event: Core.event_logger,
  request: LogStasher.logger
}.each do |tag, logger|
  url = "https://logs-01.loggly.com/inputs/#{token}/tag/#{tag}"
  loggly = Logglier.new(url, threaded: true, format: :json)
  logger.extend Core.broadcast(loggly)
end

[babelian]

This was a false positive - turned that returning the payload inside of an instrumentation block slowed it down dramatically (few seconds to finish vs instant). Returning nil or true fixed it...

ActiveSupport::Notifications.instrument 'delayed_job.perform', payload do |payload|
success = payload[:success] = block.call(job)
return payload # very slow
return nil # instant
end