Rails 4 log messages appear 2x

[gkop]

This is a brand new rails 4 rc2 app with the tweaks needed to run on heroku - https://github.com/gkop/heroku-rails-4-duplicate-logs .

Deploy to heroku, tail the logs, hit the / path, and you will see 2 log messages (404) -- http://pastie.org/8053185 .

Heroku staff - I have deployed the app for you - http://heroku-rails-4-duplicate-logs.herokuapp.com/

[hone]

Thanks for filing this. This is because rails server sends logs to STDOUT as well as to the Rails.logger which is why you're seeing this twice. If you just use rackup on that sample app, you get the logs only once.

[gkop]

You're correct.

Procfile

web: rackup -p $PORT

Did the trick.

Thanks!

Note - I did reference https://devcenter.heroku.com/articles/rails4 but glossed over the bit on unicorn configuration, since I wasn't intending on using unicorn just yet. Perhaps add a note that regardless of server, you should either execute rackup or the server binary but not rails s or script rails/server or have a missing Procfile or a Procfile missing an explicit web process.

[heartpunk]

This drove me crazy for a few hours. Glad to finally find a solution.

[heartpunk]

Maybe the docs here/at rails_12factor should reflect this?

[heartpunk]

I'll happily update them and submit a PR if that's a desirable thing.

[schneems]

Brainstorming here what could we do to fix this problem?

• Make rails s only log to one source instead of two (this behavior is a bit confusing)
  • Not a bad option but need a stronger argument than just this issue for that change.
• Detect what the top level command we're running in from this gem and don't run if it is rails server or rails s
  • this sounds very brittle and not very fun
• Check the sinks that the logger is logging to and if one of them is already STDOUT, don't execute our code
  • Wouldn't mind doing this, but I don't think it's possible given the current implementation of Logger

[hone]

@schneems didn't you fix this in Rails 4.1?

[schneems]

rails/rails#11060 was merged in and fixes this issue. There is nothing we can do for 4.0 closing this issue seems good.

[davidpelaez]

I still have this issue, and this is the most relevant result in Google. So for anyone having the problem, this is something I used in application.rb

        if Rails.env.development?
            # Don't log to STDOUT, by default rails s will handle it
            config.logger = Logger.new('/dev/null')
        else
            # Don't log to file, sending everything to unicorn file.
            config.logger = Logger.new(STDOUT)
        end

It'll probably help someone out there.

[schneems]

You can use Rails.env.development? instead of the double equals. Also make sure you remove that code when you rev to 4.1 otherwise you'll stop seeing logs in development.

[davidpelaez]

I updated the comment. Thanks for the note on 4.1 since having it posted here will sure avoid lots of future headaches. So this is all fixed in 4.1 -currently in beta-, right?

[schneems]

it should be, if it's not open an issue on rails/rails and ping me via
@schneems

On Mon, Dec 30, 2013 at 1:23 PM, David Pelaez notifications@github.comwrote:

I updated the comment. Thanks for the note on 4.1 since having it posted
here will sure avoid lots of future headaches. So this is all fixed in 4.1
-currently in beta-, right?

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/1#issuecomment-31359784
.

[styledev]

Moving the rails_12factor gem to the production group fixed the double entries for me.
http://stackoverflow.com/questions/19900093/rails-logger-appears-to-be-duplicating-log-lines

[seanahrens]

For anyone who stumbles upon this issue from google, make sure that what's actually happening to you is not that your app is actually making duplicate REQUESTS as mine was. See http://stackoverflow.com/questions/3266020/rails-app-logging-duplicate-requests/28299100#28299100

[joallard]

Got this on 4.2, adding group: :production

[raldred]

Same, looks like this issue is back in 4.2.
Brand new 4.2.4 app today and I have double logging.

[schneems]

Open a new issue and give me an example app that reproduces the problem please