7

I cannot log messages from my delayed_job process. Here is the job that is being run.

class MyJob
  def initialize(blahblah)
    @blahblah = blahblah
    @logger = Logger.new(File.join(Rails.root, 'log', 'delayed_job.log'))
  end
  def perform
    @logger.add Logger::INFO, "logging from delayed_job"
    #do stuff
  end
end

I've tried various logging levels, and I have config.log_level = :debug in my environment configuration. I run delayed_job from monit. I'm using delayed_job 3.0.1 with ruby 1.9.3 and rails 3.0.10.

Jak
  • 2,893
  • 3
  • 19
  • 33
freedrull
  • 2,194
  • 4
  • 21
  • 33
  • One idea would be that it's conflicting because delayed_job is using this log file as well. Did you try another name? – iltempo Mar 01 '12 at 00:05
  • I tried a different name. The new log file is created but nothing is logged to it. – freedrull Mar 06 '12 at 17:27

4 Answers4

17

An explation could be that the job gets initialized only once on producer side. Then it gets serialized, delivered through the queue (database for example) and unserialized in the worker. But the initialize method is not being called in the worker process again. Only the perform method is called via send.

However you can reuse the workers logger to write to the log file:

class MyJob
  def perform
    say "performing like hell"
  end

  def say(text)
    Delayed::Worker.logger.add(Logger::INFO, text)
  end
end

Don't forget to restart the workers.

iltempo
  • 15,718
  • 8
  • 61
  • 72
  • 1
    I am getting this "TestJob failed with NoMethodError: undefined method `add' for nil:NilClass". Raghus's answer fixed that. – idrinkpabst Apr 23 '13 at 22:05
11

In RAILS_ROOT/config/initializers have a file called delayed_job_config.rb with these lines:

Delayed::Worker.logger = Rails.logger
Delayed::Worker.logger.auto_flushing = true

Remember to re-start your workers after doing this.

Let me know if this helps

raghus
  • 113
  • 6
  • 1
    `auto_flushing` was deprecated in rails 3 and seems to have been removed in later versions – Jared Beck Jul 24 '17 at 19:05
  • See [Rails-3.2 deprecation notices](http://guides.rubyonrails.org/3_2_release_notes.html#deprecations) for potential remedies to the removal of `auto_flushing`. – Pete Apr 03 '18 at 16:26
  • Hi I tried to add those lines in delayed_job_config.rb, but the delayed job log is not still written in the rails application log – Satria Janaka Mar 18 '22 at 07:44
3

I don't see why you would set the logger in the job. When I've done this I set the worker to to use a specific file on start e.g. Logger.new("log/worker_#{worker_number}") which ensures that each worker outputs to it's own file and you don't have to worry about multiple workers writing to the same file at the same time (messy).

Also, in plain ol' ruby you can call @logger.info "logging from delayed_job".

Finally, i'm pretty sure that 'perform' is called directly by your worker and instantiated, so you can refactor to:

class MyJob
 def perform(blahblah)
  @logger.add Logger::INFO, "logging from delayed_job"
  @blahblah = blahblah
  #do stuff
 end
end
TomDunning
  • 4,829
  • 1
  • 26
  • 33
  • I actually wasn't able to refactor that way, I don't think perform takes any arguments. I didn't try your logging method since the previous answer worked, but I believe I remember trying that before and it didn't work. – freedrull Mar 14 '12 at 17:06
  • You are right though, I should set the logger in an initializer or something instead of setting it in the job. – freedrull Mar 14 '12 at 17:07
0

This is working just fine for me in Rails 3.2:

class FiveMinuteAggregateJob < Struct.new(:link, :timestamp)
  def perform
    Rails.logger.info 'yup.'
  end
end
thisisbrians
  • 177
  • 1
  • 6