28

When i view my heroku logs on the server (with heroku logs --tail --app myapp) i see something like this:

2011-06-21T14:09:25+00:00 app[web.1]: Started PUT "/reports/19.xml" for 77.89.149.137 at 2011-06-21 07:09:25 -0700
2011-06-21T14:09:25+00:00 heroku[router]: PUT myapp.heroku.com/reports/19.xml dyno=web.1 queue=0 wait=0ms service=7ms status=401 bytes=28
2011-06-21T14:09:26+00:00 heroku[nginx]: PUT /reports/19.xml HTTP/1.1 | 77.89.149.137 | 656 | http | 401

While in my local log i'd see something like this:

Started PUT "/reports/19" for 127.0.0.1 at 2011-06-21 15:27:01 +0100
  Processing by ReportsController#update as XML
  Parameters: {"report"=>{"workflow_status"=>"3"}, "id"=>"19"}
  Person Load (0.9ms)  SELECT "people".* FROM "people" WHERE "people"."email" = 'madeupemai@lkklj.com' LIMIT 1
  Report Load (0.4ms)  SELECT "reports".* FROM "reports" WHERE "reports"."id" = 19 LIMIT 1
DEPRECATION WARNING: Object#returning has been deprecated in favor of Object#tap. (called from update_report at /home/max/work/rails_apps/flamingo_container/flamingo/vendor/plugins/resource_this/lib/resource_this.rb:135)
Creating scope :open. Overwriting existing method Task.open.
  Task Load (2.0ms)  SELECT "tasks".* FROM "tasks" WHERE "tasks"."id" = 14 LIMIT 1
Completed 200 OK in 1648ms (Views: 568.2ms | ActiveRecord: 3.2ms)

Ie with a lot more information, particularly the params, info from the router, generated sql, any templates rendered etc etc.

Does anyone know how i can get my heroku log to be as verbose as my development one? I've done the following already:

1) Set the log level in the relevant (rails 3) environment file:

config.log_level = :debug

2) Told heroku to use a different logger level, as described on http://devcenter.heroku.com/articles/logging

heroku config:add LOG_LEVEL=DEBUG --app myapp #from CLI

Neither has made any difference...any ideas anyone?
thanks, max

Max Williams
  • 32,435
  • 31
  • 130
  • 197

6 Answers6

40

You're essentially wanting to show the SQL / params output in the Heroku logs. You can do this by adding the line shown below to the config block within your production.rb file:

MyAppNameHere::Application.configure do

  # add this line
  config.logger = Logger.new(STDOUT)

end

By the way, setting the log level to debug just means that Rails.logger.debug will output to the logs when you're on Heroku

iwasrobbed
  • 46,496
  • 21
  • 150
  • 195
  • 2
    Awesome! That worked for me too and Heroku support told me that one of my gem is overriding the output. It might be more appropriate to add the code to `production.rb` instead of `application.rb`, just a thought. – Bob Aug 08 '11 at 21:49
  • 1
    This works really well but now it seems setting the "heroku config:add LOG_LEVEL=FATAL" does nothing. All the logs are now displayed nomatter what I set the LOG_LEVEL to. – bradgonesurfing Aug 24 '11 at 11:23
  • 1
    By the way I just tried this and it sent the app into a crash cycle – Jesse Clark Mar 06 '12 at 22:02
  • 1
    This doesn't work for me either. Maybe it worked on one of the non-cedar stacks? – heartpunk Nov 05 '12 at 04:14
  • is it safe to set the log level to debug on heroku production? – BenKoshy Sep 29 '16 at 21:10
  • @BKSpurgeon I'd avoid doing so. Likely too noisy and may expose you to security issues – iwasrobbed Sep 29 '16 at 21:37
  • you could leak personal information by doing that, but it's useful for debugging – Dorian Nov 07 '21 at 16:06
2

In your production.rb add config.log_level = :debug and redeploy. That will give you the same logs as development mode :)

Zach Inglis
  • 1,242
  • 1
  • 14
  • 28
  • Hmm. Have you tried capturing them with other methods? Something quick and dirty like http://railscasts.com/episodes/277-mountable-engines may do the trick. Obviously it's overkill for what you need but if nothing else is working... Or do you think it's purely the logger not actually outputting that information? – Zach Inglis Aug 01 '11 at 17:07
1

The detailed log you want is generated by the function start_processing in log_subscriber.rb.

action_controller/log_subscriber.rb:

def start_processing(event)
  payload = event.payload
  params  = payload[:params].except(*INTERNAL_PARAMS)

  info "  Processing by #{payload[:controller]}##{payload[:action]} as #{payload[:formats].first.to_s.upcase}"
  info "  Parameters: #{params.inspect}" unless params.empty?
end

I checked with rails 3.0.4 in development and production environment. In both environments, we have the detailed logs.

This is an info level log. That's why the debug log level is not changing the output.

I installed the plugin used by heroku rails_log_stdout (Heroku logging) but I still have the desired output.

Right now, I can't test with heroku to find out why you don't have all the logs.

In the heroku example (see Heroku logging, section log retrieval), we don't see the "Processing" and "Parameters" lines. I think that either this method is not called when the app is running on heroku (it is somehow disabled) or heroku skips logs starting with whitespaces. Could you try to log messages starting with whitespaces and see if heroku is showing them?

Pticed
  • 31
  • 2
0

The real problem is actually due to the way Heroku works in conjunction with rails. The right way to solve this is to add: gem 'rails_12factor', group: :production

See https://devcenter.heroku.com/articles/rails-integration-gems for more info on the matter

Niels Kristian
  • 8,661
  • 11
  • 59
  • 117
0

Looks like the puma server doesn't play well with Heroku. In my project, I tried everything, but it still wouldn't log. I then replaced Puma with Unicorn, and bam, full logs are being shown.

Ali
  • 261,656
  • 265
  • 575
  • 769
0

Rails doesn't generate those logs when in production mode. http://groups.google.com/group/heroku/browse_thread/thread/d778fafedc9a378a

  • 1
    It does in my rails 2 apps. Is this a change in rails 3? I'm more inclined to believe it's something heroku specific. – Max Williams Aug 01 '11 at 08:35