CODEWITHSUNDEEP
ruby-on-railsherokuloggingruby-on-rails-5
lunr
lunr

Reputation: 5269

Logs don't flush in Rails 5

We have an Rails 5 application running on Heroku. When we try to run-off process using heroku run:detached, the log doesn't appear until the process exits. An example:

$ heroku run:detached 'rails runner "Rails.logger.info 1;(1..500000000).each{};"'
Running rails runner "Rails.logger.info 1;(1..500000000).each{};" on ⬢ <REDACTED>... done, run.7268 (Standard-1X)
Run heroku logs --app <REDACTED> --dyno run.7268 to view the output.
$ heroku logs --dyno run.7268 -t
2019-10-24T13:49:29.846280+00:00 heroku[run.7268]: Starting process with command `rails runner "Rails.logger.info 1;(1..500000000).each{};"`
2019-10-24T13:49:30.582293+00:00 heroku[run.7268]: State changed from starting to up
2019-10-24T13:50:01.002636+00:00 heroku[run.7268]: State changed from up to complete
2019-10-24T13:50:00.982354+00:00 heroku[run.7268]: Process exited with status 0
2019-10-24T13:50:00.930084+00:00 app[run.7268]: I, [2019-10-24T13:49:35.871352 #4]  INFO -- : 1

The log doesn't appear before the process exits. You can see the Rails timestamp of the last line is 13:49:35, while the log timestamp is 13:50:00. We see the same behavior in our Rails 6 application, but not in Rails 4 application.

Upvotes: 0

Views: 560

Answers (1)

lunr
lunr

Reputation: 5269

We found out this is because of buffering in Rails logger which is enabled in production mode. You can disable it with STDOUT.sync = true in production.rb file.

Upvotes: 2

Related Questions