我如何获得Rails 5日志来显示每个操作的许多细节，就像Rails 4所做的那样?

For some reason, even in development, my Rails 5 log only shows me some information.

出于某种原因，即使在开发中，我的Rails 5日志也只显示了一些信息。

I am not sure how it chooses what to show.

我不知道它是如何选择展示什么。

I don't know if it is because I have Turbolinks installed, but I doubt it.

我不知道是不是因为我安装了Turbolinks，但我怀疑它。

Was there a change in the way Rails logs requests in development in Rails 5 over 4?

Rails在Rails 5 / 4开发中记录请求的方式是否发生了变化?

Edit 1

编辑1

This is hard to show fully here, but here is an example.

这很难在这里充分展示，但这里有一个例子。

I restarted my server, then I visited my root_path which is questions#index. Then I went to an individual question question#show, then I refreshed that show page. This is what the log shows of those 3 requests:

我重新启动了服务器，然后访问了我的root_path，这是问题#index。然后我去了一个独立的问题#show，然后我刷新了那个show page。这是日志显示的3个请求:

$ rails s
=> Booting Puma
=> Rails 5.0.0.rc1 application starting in development on http://localhost:3000
=> Run `rails server -h` for more startup options
Puma starting in single mode...
* Version 3.4.0 (ruby 2.3.0-p0), codename: Owl Bowl Brawl
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://localhost:3000
Use Ctrl-C to stop
Started GET "/" for ::1 at 2016-05-16 16:08:03 -0500
  ActiveRecord::SchemaMigration Load (1.0ms)  SELECT "schema_migrations".* FROM "schema_migrations"
Processing by QuestionsController#index as HTML
  Rendering questions/index.html.erb within layouts/application
  Rendered shared/_main_page_heading.html.erb (0.3ms)
  Question Load (1.1ms)  SELECT "questions".* FROM "questions"
  User Load (1.5ms)  SELECT "users".* FROM "users" WHERE "users"."id" IN (1521, 1522, 1523, 1524, 1525, 1526, 1527, 1528, 1529, 1530, 1531, 1532, 1533, 1534, 1535, 1536, 1537, 1538)
   (1.1ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 4]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 4]]
  Rendered questions/_question.html.erb (443.5ms)
   (1.9ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 5]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 5]]
  Rendered questions/_question.html.erb (5.2ms)
   (1.7ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 6]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 6]]
  Rendered questions/_question.html.erb (4.9ms)
   (1.9ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 7]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 7]]
  Rendered questions/_question.html.erb (5.0ms)
   (1.8ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 8]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 8]]
  Rendered questions/_question.html.erb (5.2ms)
   (1.7ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 9]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 9]]
  Rendered questions/_question.html.erb (5.0ms)
   (1.7ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 10]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 10]]
  Rendered questions/_question.html.erb (5.4ms)
   (2.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 11]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 11]]
  Rendered questions/_question.html.erb (5.7ms)
   (1.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 12]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 12]]
  Rendered questions/_question.html.erb (3.2ms)
   (1.6ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 13]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 13]]
  Rendered questions/_question.html.erb (5.0ms)
   (1.1ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 14]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 14]]
  Rendered questions/_question.html.erb (4.8ms)
   (1.4ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 15]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 15]]
  Rendered questions/_question.html.erb (4.9ms)
   (2.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 16]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 16]]
  Rendered questions/_question.html.erb (7.4ms)
   (2.2ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 17]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 17]]
  Rendered questions/_question.html.erb (6.6ms)
   (2.1ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 18]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 18]]
  Rendered questions/_question.html.erb (6.3ms)
   (1.1ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 19]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 19]]
  Rendered questions/_question.html.erb (3.9ms)
   (1.5ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 20]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 20]]
  Rendered questions/_question.html.erb (6.1ms)
   (1.2ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 21]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 21]]
  Rendered questions/_question.html.erb (3.6ms)
  Rendered questions/index.html.erb within layouts/application (621.0ms)
  Rendered shared/_navbar.html.erb (1.1ms)
Completed 200 OK in 1917ms (Views: 1844.9ms | ActiveRecord: 52.9ms)

It only shows me the first operation, not the 2nd 2.

它只告诉我第一个操作，而不是第二个。

Say I stop the server, while still on /questions/4, then restart it and refresh and then go back to the home page, this is what the log shows:

假设我停止服务器，但仍然在/questions/4上，然后重新启动并刷新，然后返回到主页，日志显示如下:

$ rails s
=> Booting Puma
=> Rails 5.0.0.rc1 application starting in development on http://localhost:3000
=> Run `rails server -h` for more startup options
Puma starting in single mode...
* Version 3.4.0 (ruby 2.3.0-p0), codename: Owl Bowl Brawl
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://localhost:3000
Use Ctrl-C to stop
Started GET "/questions/4" for ::1 at 2016-05-16 16:10:55 -0500
  ActiveRecord::SchemaMigration Load (1.4ms)  SELECT "schema_migrations".* FROM "schema_migrations"
Processing by QuestionsController#show as HTML
  Parameters: {"id"=>"4"}
  Question Load (1.1ms)  SELECT  "questions".* FROM "questions" WHERE "questions"."id" = $1 LIMIT $2  [["id", 4], ["LIMIT", 1]]
  Rendering questions/show.html.erb within layouts/application
  User Load (1.1ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2  [["id", 1521], ["LIMIT", 1]]
   (2.2ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 4]]
  CACHE (0.0ms)  SELECT COUNT(*) FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 4]]
  Answer Load (2.8ms)  SELECT "answers".* FROM "answers" WHERE "answers"."question_id" = $1  [["question_id", 4]]
  User Load (3.1ms)  SELECT  "users".* FROM "users" ORDER BY RANDOM() LIMIT $1  [["LIMIT", 1]]
  Rendered answers/_form.html.erb (535.9ms)
  Rendered questions/show.html.erb within layouts/application (637.2ms)
  Rendered shared/_navbar.html.erb (1.2ms)
Completed 200 OK in 2666ms (Views: 2575.6ms | ActiveRecord: 34.4ms)

It doesn't show the 2nd request, just the first. It could be because it is being cached or maybe Turbolinks is serving up the last version of the page from my cache or something, but the point is that I am not seeing the request hit my server at all.

它不显示第二个请求，只显示第一个请求。这可能是因为它正在被缓存，或者可能是Turbolinks正在为我的缓存或其他东西提供页面的最后一个版本，但关键是我根本看不到请求击中我的服务器。

Not sure how to get all 2 or 3 requests to show up in my log. It is hard to show something not showing up, but I hope this explains it a bit better.

不知道如何在日志中显示所有2或3个请求。很难显示没有出现的东西，但我希望这能更好地解释它。

2 个解决方案

#1

After having the same problem using rails 5 rc1 and puma 3.4.0 I figured out the problem has to do with quiet_assets gem having thread-safe issues. So your options are:

在使用rails 5 rc1和puma 3.4.0遇到同样的问题后，我发现这个问题与存在线程安全问题的quiet_assets gem有关。所以你的选择是:

Set an env variable RAILS_MAX_THREADS=1 to run just one thread locally.
将env变量RAILS_MAX_THREADS=1设置为本地运行一个线程。
Or delete quiet_assets from your Gemfile and have a messy log until quiet assets be finally implemented to rails 5.
或者从Gemfile中删除quiet_assets，并有一个混乱的日志，直到最后实现到rails 5的静默资产。

UPDATE

更新

sprockets-rails has finally added the config.assets.quiet option. So the final solution is to update sprockets-rails (and rails 5 also as there is finally a stable version) and add:

sprockets-rails最终添加了config.assets。安静的选项。因此，最终的解决方案是更新sprockets-rails(以及rails 5，因为最终还有一个稳定的版本)并添加:

#config/environments/development.rb
config.assets.quiet = true

#2

You can control it by setting the appropriate log level in your config/environments/.rb file, e.g.:

您可以通过在配置/环境中设置适当的日志级别来控制它。rb文件,例如:

config.log_level = :debug

配置。log_level =:调试

#1