15

I've got a rails 3.1 app deployed on Heroku Cedar. I'm having a problem with the logging. The default rails logs are working just fine, but when I do something like:

logger.info "log this message"

In my controller, Heroku doesn't log anything. When I deploy my app I see the heroku message "Injecting rails_log_stdout" so I think calling the logger should work just fine. Puts statements end up in my logs. I've also tried other log levels like logger.error. Nothing works. Has anyone else seen this?

joshuacronemeyer
  • 1,316
  • 1
  • 10
  • 20

4 Answers4

35

MBHNYC's answer works great, but it makes it difficult to change the log level in different environments without changing the code. You can use this code in your environments/production.rb to honor an environment variable as well as have a reasonable default:

# https://github.com/ryanb/cancan/issues/511
config.logger = Logger.new(STDOUT)
config.logger.level = Logger.const_get((ENV["LOG_LEVEL"] || "INFO").upcase)

Use this command to set a different log level:

heroku config:set LOG_LEVEL=error
Phil Calvin
  • 5,077
  • 2
  • 41
  • 35
  • Excellent Phil, this is a superior solution. – MBHNYC May 31 '12 at 15:21
  • I have modified this to `upcase` the string before it's passed to `const_get`, which is case-sensitive. Otherwise you might get an error from Heroku if you set the `LOG_LEVEL` variable to a lowercase value: `2012-12-05T21:38:14+00:00 app[worker.1]: wrong constant name debug` – Phil Calvin Dec 05 '12 at 21:43
  • 1
    [It seems that Heroku removed reverences to `LOG_LEVEL` from their docs within a month or so of this answer](https://web.archive.org/web/20121115084356/devcenter.heroku.com/articles/logging). Currently, it seems it would be better to do this: `config.log_level = ENV['LOG_LEVEL'] ? ENV['LOG_LEVEL'].to_sym : :info` – user664833 Jan 09 '14 at 19:01
  • @user664833: I've updated the answer to make it clear LOG_LEVEL doesn't get any special treatment by Heroku anymore. What's superior about setting this as a symbol as opposed to as a constant? I tend to prefer my answers to be "what I've got in production" so I know they work, but I'm curious now. – Phil Calvin Jan 10 '14 at 14:24
  • @PhilCalvin, in Rails `4` the default `config/environments/production.rb` uses a symbol (`config.log_level = :info`), so I followed suit. As a matter of taste, I find the code in my previous comment to look cleaner. And the capitalization and use of `upcase` are also relics now. Further, in Rails `4` you will likely be using [rails_12factor](https://github.com/heroku/rails_12factor), which depends on [rails_stdout_logging](https://github.com/heroku/rails_stdout_logging/), which *ensures that your logs will be sent to standard out*. Note that `rails_stdout_logging` also supports Rails `3`. – user664833 Jan 10 '14 at 17:48
20

I was just having the same issue, solved by using the technique here:

https://github.com/ryanb/cancan/issues/511

Basically, you need to specify the logger outputs to STDOUT, some gems interfere with the logger and seem to hijack the functionality (cancan in my case).

For the click lazy, just put this in environments/production.rb

config.logger = Logger.new(STDOUT) 
config.log_level = :info
Phil Calvin
  • 5,077
  • 2
  • 41
  • 35
MBHNYC
  • 1,268
  • 1
  • 13
  • 25
  • 2
    Heroku support was leading me in a similar direction. Here is a list of gems they claim cause this problem: acts_as_audited, on_the_spot, restful_jsonp, authlogic, cancan, simple-navigation – joshuacronemeyer Nov 28 '11 at 18:24
  • 1
    the second line should be `config.logger.level = Logger::INFO` – Matt Sanders Nov 01 '12 at 21:11
4

As of the moment, it looks like heroku injects these two plugins when building the slug:

rails_log_stdout - https://github.com/ddollar/rails_log_stdout

rails3_server_static_assets - https://github.com/pedro/rails3_serve_static_assets

Anything sent to the pre-existing Rails logger will be discarded and will not be visible in logs. Just adding this for completeness for anyone else who ends up here.

Matt Sanders
  • 8,023
  • 3
  • 37
  • 49
  • That's wrong. What Heroku does is dump its own output to stdout. That's why you are supposed to set your rails to dump into stdout as well – enthrops May 01 '13 at 23:36
  • To clarify, what part of what I said are you thinking is wrong? Yes, heroku sends output to stdout. The plugin addresses this by replacing the logger with a logger that logs to stdout. Anything logged before the logger is replaced to the original Rails logger will never be visible. – Matt Sanders May 02 '13 at 18:17
  • Sorry, I'm not sure how it all really works at this point. BTW, the plugin you mentioned in your answer is not the plugin that Heroku currently injects – enthrops May 02 '13 at 18:31
4

The problem, as @MBHNYC correctly addressed, is that your logs are not going to STDOUT.

Instead of configuring manually all that stuff, Heroku provides a gem that does this all for you.

Just put 

gem 'rails_12factor', group: :production

in your Gemfile, bundle, and that's it!

NOTE: This works both for Rails 3 and 4.

Source: Rails 4 on Heroku

finiteautomata
  • 3,753
  • 4
  • 31
  • 41
  • 1
    OMG thank you for this. Just wasted like a day of debugging because I grouped this gem into the wrong environment so logs were not showing up. – vinhboy Oct 04 '19 at 00:59