delayed_job.log is always empty in RAILS_ENV=production

1,202 views
Skip to first unread message

NwP

unread,
Dec 8, 2009, 9:16:08 PM12/8/09
to delayed_job
When run under the production environment (RAILS_ENV=production) the
delayed_job.log is always empty. When run in an identical environment
set to RAILS_ENV=staging the delayed_job file is not empty. However,
on deploy staging.rb is copied from production.rb so they're
identical. Why does one produce logging while other does not. FYI:
under both scenarios delayed job is successfully going its job--I just
want to figure out why it doesn't produce any logging when run under
production.

Thanks,

Nathan

Irish

unread,
Dec 11, 2009, 4:15:48 PM12/11/09
to delayed_job
I'm seeing the same behavior, not sure why yet

Menno van der Sman

unread,
Jan 6, 2010, 9:42:48 AM1/6/10
to delayed_job
I'm also experiencing this behavior. Does anybody already have a fix
or workaround for this?

Thanks,

Menno

Brandon Keepers

unread,
Jan 6, 2010, 11:44:15 AM1/6/10
to delay...@googlegroups.com
I haven't really looked into it. I can give you pointers. When the process is daemonized, all of the open file pointers are closed. So the Worker reopens all file pointers that were open and points them at log/delayed_job.log. There seems to be something wrong with that in production.

The current method of daemonizing really sucks. I'd like to rewrite the background process to use a unicorn style pre-forking worker, but haven't had time to tackle it yet.

Brandon

Allan Grant

unread,
Feb 3, 2010, 8:41:03 PM2/3/10
to delayed_job
I'm having the same problem too. It's driving me nuts. Has anyone
found a solution or cause or yet?

Thanks,

Allan

Woody Peterson

unread,
Feb 3, 2010, 11:29:40 PM2/3/10
to delay...@googlegroups.com
I haven't had the problem nor investigated, but I'm gonna put out a
hunch anyways: DJ is using Rails' buffered log in production, and
flushing the buffer is not being triggered for some reason (don't know
if it's flushed by buffer size or explicitly flushed after a request).

Nathan Phelps

unread,
Feb 4, 2010, 2:22:51 AM2/4/10
to delay...@googlegroups.com
THANK YOU Woody!  This was indeed the issue. When in production the buffered log is set to an auto_flushing value of 1000 which means that flush is not called until 1000 messages have been logged.  Assuming you're using collectiveidea's fork of delayed_job, you can address this by setting auto_flushing to a more reasonable value in command.rb right after the logger is initialized on line 64.  I.E.

Delayed::Worker.logger = Rails.logger
Delayed::Worker.logger.auto_flushing = 1 # or whatever

I'm so happy this is resolved.  Like you Allen, it was driving me nuts!

Thanks,

Nathan

Brandon Keepers

unread,
Feb 4, 2010, 10:35:41 AM2/4/10
to delay...@googlegroups.com
Thanks for figuring that out.  I'll apply the patch and push a new version today.

Brandon

Allan Grant

unread,
Feb 4, 2010, 8:48:13 PM2/4/10
to delayed_job
Rockstar! Thanks for figuring this out, guys!

Allan

On Feb 3, 11:22 pm, Nathan Phelps <nat...@nathanwphelps.com> wrote:
> THANK YOU Woody!  This was indeed the issue. When in production the buffered
> log is set to an auto_flushing value of 1000 which means that flush is not
> called until 1000 messages have been logged.  Assuming you're using
> collectiveidea's fork of delayed_job, you can address this by setting
> auto_flushing to a more reasonable value in command.rb right after the
> logger is initialized on line 64.  I.E.
>
> Delayed::Worker.logger = Rails.logger
> Delayed::Worker.logger.auto_flushing = 1 # or whatever
>
> I'm so happy this is resolved.  Like you Allen, it was driving me nuts!
>
> Thanks,
>
> Nathan
>

Ryan McGeary

unread,
Mar 6, 2010, 8:01:12 AM3/6/10
to delayed_job
Brandon,

I see that you bumped the gemspec to 1.8.5 back when you fixed this,
but that version isn't on gemcutter yet. Would you mind publishing
v1.8.5 to gemcutter?

Thanks,
Ryan

On Feb 4, 10:35 am, Brandon Keepers <bran...@opensoul.org> wrote:
> Thanks for figuring that out.  I'll apply the patch and push a new version today.
>
> Brandon
>
> On Feb 4, 2010, at 2:22 AM, Nathan Phelps wrote:
>
> > THANK YOU Woody!  This was indeed the issue. When in production the buffered log is set to an auto_flushing value of 1000 which means that flush is not called until 1000 messages have been logged.  Assuming you're using collectiveidea's fork of delayed_job, you can address this by setting auto_flushing to a more reasonable value in command.rb right after the logger is initialized on line 64.  I.E.
>
> > Delayed::Worker.logger = Rails.logger
> > Delayed::Worker.logger.auto_flushing = 1 # or whatever
>
> > I'm so happy this is resolved.  Like you Allen, it was driving me nuts!
>
> > Thanks,
>
> > Nathan
>

Nathan Phelps

unread,
Mar 14, 2010, 11:10:52 PM3/14/10
to delay...@googlegroups.com
I second this.

Brandon Keepers

unread,
Mar 15, 2010, 11:29:13 AM3/15/10
to delay...@googlegroups.com
I've pushed 1.8.5.  You can view changes here: http://wiki.github.com/collectiveidea/delayed_job/changelog

Sorry for the delay on this release.  I've been wanting to get a 2.0 pushed soon, but it will still be a little ways off.

Thanks,
Brandon
Reply all
Reply to author
Forward
0 new messages