heroku上のRailsアプリケーションのログ出力方法ついて

Question

概要

現在、Railsアプリケーションの作成をし、herokuにデプロイを試みています。

デプロイ後、アクセスをすると500レスポンスが返りアクセスができない状態です。
heroku logs で確認しましたが、具体的なログが出力されません。

アプリケーションログの具体的な出力方法をお伺いしたいです。

事象

アクセス時に500がレスポンスとして返る
heroku上にエラーログが出力されない

2021-10-10T02:32:50.867698+00:00 heroku[router]: 
at=info method=GET path="/" host=estate-review.herokuapp.com 
request_id=0ae3ade9-8683-4e31-a362-37e7a506a3cd 
fwd="59.169.255.123" 
dyno=web.1 connect=0ms service=2125ms status=500 bytes=189 protocol=https

環境

Ruby 2.7.4
Rails 6.0.4.1
Docker version 20.10.7, build f0df350

試したこと

ログ出力の設定

config/environments/production.rbにログの出力設定を行いました。

# log_levelをdebug→infoに
config.log_level = :info

# loggerの設定
if ENV["RAILS_LOG_TO_STDOUT"].present?
  logger           = ActiveSupport::Logger.new(STDOUT)
  logger.formatter = config.log_formatter
  config.logger    = ActiveSupport::TaggedLogging.new(logger)
end

# RAILS_LOG_TO_STDOUTをheroku configに設定
heroku config:set RAILS_LOG_TO_STDOUT=true

Comments

[neko_daisuki]

heroku logs には rails が起動したログもないのですか？

[msk6252]

説明が足りずに申し訳ありません。
pumaの起動ログは吐き出されていますが、アプリケーションログが表示されません。
現在は500エラーが出ていますが、そのエラー詳細を確認できないため質問した次第です。

起動ログは下記のように表示されています。
---------------
2021-10-17T13:55:06.376342+00:00 heroku[web.1]: Starting process with command `bundle exec puma -C config/puma.rb`
2021-10-17T13:55:07.812151+00:00 app[web.1]: Puma starting in single mode...
2021-10-17T13:55:07.812182+00:00 app[web.1]: * Version 4.3.8 (ruby 2.7.4-p191), codename: Mysterious Traveller
2021-10-17T13:55:07.812186+00:00 app[web.1]: * Min threads: 5, max threads: 5
2021-10-17T13:55:07.812186+00:00 app[web.1]: * Environment: production
2021-10-17T13:55:10.697103+00:00 app[web.1]: DEPRECATION WARNING: Including LoggerSilence is deprecated and will be removed in Rails 6.1. Please use `ActiveSupport::LoggerSilence` instead (called from <top (required)> at /webapp/config/application.rb:7)
2021-10-17T13:55:11.997746+00:00 heroku[web.1]: State changed from starting to up
2021-10-17T13:55:11.793712+00:00 app[web.1]: * Listening on tcp://0.0.0.0:19341
2021-10-17T13:55:11.793963+00:00 app[web.1]: * Listening on unix:///webapp/tmp/sockets/puma.sock
2021-10-17T13:55:11.794233+00:00 app[web.1]: Use Ctrl-C to stop

[neko_daisuki]

LoggerSilence is deprecated
名前からして怪しいですが application.rb の7行目はどうなっていますか？

[msk6252]

ご返信ありがとうございます。

ご指摘の "LoggerSilence is deprecated" についてですが、こちらは試しに入れていたGem 'rails_12factor'が要因でWARNINGが出ていたようです。
Gem削除→デプロイしたところWARNINGが消えました。
念の為ですが、application.rbの7行目は、”Bundler.require(*Rails.groups)”の記述でした。

こちらも念の為、application.rbの内容を記載します。
-------------
require_relative 'boot'

require 'rails/all'

# Require the gems listed in Gemfile, including any gems
# you've limited to :test, :development, or :production.
Bundler.require(*Rails.groups)

module Webapp
class Application < Rails::Application
# Initialize configuration defaults for originally generated Rails version.
config.load_defaults 6.0

# Settings in config/environments/* take precedence over those specified here.
# Application configuration can go into files in config/initializers
# -- all .rb files in that directory are automatically loaded after loading
# the framework and any gems in your application.
end

[neko_daisuki]

助けになれるか分かりませんが、
heroku run rails c して
pp Rails.application.config.logger
の結果を張り付けてみてください

[msk6252]

ありがとうございます。
ご指示いただいた出力結果を記載します。
------
irb(main):002:0> pp Rails.application.config.logger
#<Syslog::Logger:0x00005587f5b00810
@facility=8,
@formatter=#<Syslog::Logger::Formatter:0x00005587f5b00748>,
@level=1>
=> #<Syslog::Logger:0x00005587f5b00810 @level=1, @formatter=#<Syslog::Logger::Formatter:0x00005587f5b00748>, @facility=8>

[neko_daisuki]

こちらの環境では以下のようになっています。
#<ActiveSupport::Logger:0x00005628d7ea84d0
@default_formatter=
#<Logger::Formatter:0x00005628d7d64088 @datetime_format=nil>,
@formatter=#<Logger::Formatter:0x00005628d7ea8390 @datetime_format=nil>,
@level=1,
@logdev=
#<Logger::LogDevice:0x00005628d7eb3f10
@binmode=false,
@dev=#<IO:<STDOUT>>,
@filename=nil,
@mon_data=#<Monitor:0x00005628d7eb3ee8>,
@mon_data_owner_object_id=51720,
@shift_age=nil,
@shift_period_suffix=nil,
@shift_size=nil>,
@progname=nil>

environments/production.rb を確認したところ、
ログの設定の上の方にsyslog の設定例がコメントアウトされて載っていましたが(rails7.0.0a2)
ここはどうなっていますか？

それから、heroku run rails c して ENV["RAILS_LOG_TO_STDOUT"] と打つと nil になりませんか？

[msk6252]

返信が遅くなり申し訳ありません。
ご指摘頂いた内容に回答致します。
1. heroku run rails c して ENV["RAILS_LOG_TO_STDOUT"] を打つとnilにならないか
heroku側の環境変数にRAILS_LOG_TO＿STDOUTに対応する値を設定しておりましたので、nilでは帰ってきませんでした。（設定値："true"）

2. config/environments/production.rbの設定
こちら直接の回答にはなりませんが、元々ActiveSupportを利用していたものを試す段階でLoggerに変更していました。
こちらActiveSupportに変更しましたが、ログの出力内容は変わりませんでした。

[neko_daisuki]

どこかでロガーの設定を書き換えてるんじゃないでしょうか。
あやしいのは config/application.rb、config/initializers/ 以下のファイルです。

[msk6252]

コメントありがとうございます。
ご指摘頂いた場所のコミットログを遡って確認したいと思います。