I have a Rails app, and some custom rake tasks which are called by cron jobs every hour or so. The rake tasks would just call some methods on my models to perform some work. The models in turn use RAILS_DEFAULT_LOGGER.info to emit messages to the log file as needed. For a good long time everything was working fine, but recently I noticed that my rake tasks are not resulting in any log file messages. I know that they are running because the database is getting get updated as expected. I then tried to manually run script/console in production mode, and manually did this:>> RAILS_DEFAULT_LOGGER.info "hello world"and this did not appear in the log file either. Anyone have any ideas? Thanks! Jeff --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Jeff Cohen wrote:> I then tried to manually run script/console in production mode, and > manually did this: > >>> RAILS_DEFAULT_LOGGER.info "hello world" > > and this did not appear in the log file either. > > Anyone have any ideas?What response to you get in console? Maybe clear your log file? -- Posted via http://www.ruby-forum.com/. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
On Apr 9, 11:40 am, Daniel Waite <rails-mailing-l...-ARtvInVfO7ksV2N9l4h3zg@public.gmane.org> wrote:> What response to you get in console? > > Maybe clear your log file? > --Sorry I should have mentioned that originally. I get a good response from the console: $ script/console production Loading production environment (Rails 2.0.2)>> RAILS_DEFAULT_LOGGER.info "hello world"=> "hello world\n">>but when I tail the log I don''t see "hello world" anywhere (even a full grep fails). I also tried stopping the mongrel cluster, then rake log:clear, then started the cluster again, and still no output. Output from the Rails app itself is working great - I see all the usual rails logging as it processes requests, etc. Truly stumped on this one. Jeff --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe@googlegroups.com For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
What have you got your log level set to? Try sending your logger object the method error "hello world" Julian. Learn Ruby on Rails! Check out the FREE VIDS (for a limited time) VIDEO #3 out NOW! http://sensei.zenunit.com/ On 10/04/2008, at 3:56 AM, Jeff wrote:> > On Apr 9, 11:40 am, Daniel Waite <rails-mailing-l...-ARtvInVfO7ksV2N9l4h3zg@public.gmane.org> > wrote: >> What response to you get in console? >> >> Maybe clear your log file? >> -- > > Sorry I should have mentioned that originally. I get a good response > from the console: > > $ script/console production > Loading production environment (Rails 2.0.2) >>> RAILS_DEFAULT_LOGGER.info "hello world" > => "hello world\n" >>> > > but when I tail the log I don''t see "hello world" anywhere (even a > full grep fails). > > I also tried stopping the mongrel cluster, then rake log:clear, then > started the cluster again, and still no output. > > Output from the Rails app itself is working great - I see all the > usual rails logging as it processes requests, etc. > > Truly stumped on this one. > > Jeff > >--~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
On Apr 10, 1:29 am, Julian Leviston <jul...-AfxEtdRqmE/tt0EhB6fy4g@public.gmane.org> wrote:> What have you got your log level set to?I haven''t knowingly changed it from the way Rails configures it for production. I can do this script/console:>> RAILS_DEFAULT_LOGGER.info? >> trueThat was a good thought, though... any others? :-) Jeff --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe@googlegroups.com For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
did you delete an recreate the log file? you may have messed the file permissions. -- Posted via http://www.ruby-forum.com/. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
On Apr 10, 8:43 am, Thorsten Mueller <rails-mailing-l...@andreas- s.net> wrote:> did you delete an recreate the log file? > you may have messed the file permissions.Another good suggestion! But file permissions seem to be ok. The good news is I''ve somehow worked around it by putting this as the first line in all of my rake tasks: RAILS_DEFAULT_LOGGER.auto_flushing = true Now I''m seeing all my output again, yay! But why should I have to do this? I think (but can''t prove) that this broke when I upgraded from 1.2.6 to 2.0.2. But if it was a Rails bug, I would think this would be biting a lot of people, not just me. Also I''m concerned about the effect this change will have on performance, so I hope someone can shed some light here. Thanks! Jeff --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe@googlegroups.com For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
This bit me too. It started happening when I upgraded from 1.2.6 to 2.0.0, just like you.Thanks for finding the workaround! --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
I just spent hours trying to figure out why my rake task was not logging in production mode. This has to be a Rails bug. I haven''t found any tickets on it yet though. The thing about ths is that it seems to work OK in development mode. Does auto_loading get set to true somewhere in the development environment? It''s not set in my file but I don''t know if it gets set somewhere in the bowels of Rails. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Jared Mehle wrote:> The thing about ths is that it seems to work OK in development mode. > Does auto_loading get set to true somewhere in the development > environment?I guess you''re asking about "auto_flushing", not "auto_loading"? In 2.0.2, /railties/lib/initializer.rb, line 254: http://github.com/github/rails/tree/c8da518bbfedc2a06b1d96912ddae00e57f21748/railties/lib/initializer.rb#L254 logger.auto_flushing = false if configuration.environment == "production" This overwrites the default as set in active_support/buffered_logger, line 41: http://github.com/github/rails/tree/c8da518bbfedc2a06b1d96912ddae00e57f21748/activesupport/lib/active_support/buffered_logger.rb#L41 @auto_flushing = 1 By the way: in upcoming releases you''ll find an additional different default: http://github.com/github/rails/tree/master/railties/lib/initializer.rb#L345-348 if configuration.environment == "production" logger.auto_flushing = false logger.set_non_blocking_io end Arjan. -- Posted via http://www.ruby-forum.com/. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
"But if it was a Rails bug, I would think this would be biting a lot of people, not just me." Thanks for your post. It took me all day just to find this page. It took the morning just to figure out that this was the problem. Since I upgraded to Rail 2.0.2, all "rake db:migrate RAILS_ENV=production" commands will fail if the migration contains any ActiveRecord commands (that would normally be logged in development mode) -- i.e. commands like [Model].find(:all), [object].update_attribute(...), etc. No problem if the migration file contains only regular migration commands (e.g. add_column, drop_table, etc.). I tried your suggestion (RAILS_DEFAULT_LOGGER.auto_flushing = true) but that only made things worse for me. That is, without that command, the rake command would eventually break and die (MySql lock would time out). But with this command, rake just hangs there forever. Why this bug hasn''t been found yet? I suspect it''s a pretty narrow case involving ActiveRecord, rake, and logger. My situation would seem common enough to have been found by others. But one can alway work around elegance to keep the trains moving. As for me, after 7 hours of banging my head on this obscure issue, I''ll just go back to a truly awful workaround (i.e. sftp ''get'' the production db to my local machine, slurp that data into my local devlopment db, run the migration locally, sftp ''put'' the updated db back up to the server, slurp it in into the production db). Maybe on another day I''ll do more than browse through the rails code in bewilderment, and actually find, fix, and publish the bug/fix. But that day is not today. :) --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Just say RAILS_DEFAULT_LOGGER.flush at the end of your Rake task. -- Posted via http://www.ruby-forum.com/. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk+unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---