如何让我的 Rails 5 日志向我显示与 Rails 4 一样的每个操作的详细信息?

Posted

技术标签:

【中文标题】如何让我的 Rails 5 日志向我显示与 Rails 4 一样的每个操作的详细信息?【英文标题】:How do I get my Rails 5 log to show me as many details about each operation like Rails 4 did? 【发布时间】:2016-09-11 22:51:48 【问题描述】:

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

我不确定它如何选择显示的内容。

我不知道是不是因为我安装了 Turbolinks,但我对此表示怀疑。

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

编辑 1

这很难在这里完全展示,但这里是一个例子。

我重新启动了我的服务器,然后我访问了我的root_path,即questions#index。然后我去了一个单独的问题question#show,然后我刷新了那个显示页面。这就是这 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)

它只显示第一个操作,而不是第二个 2。

假设我停止了服务器,但仍在/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)

它不显示第二个请求,只显示第一个。可能是因为它正在被缓存,或者 Turbolinks 正在从我的缓存中提供页面的最新版本或其他原因,但关键是我根本没有看到请求到达我的服务器。

不确定如何让所有 2 或 3 个请求显示在我的日志中。很难显示未显示的内容,但我希望这能更好地解释它。

【问题讨论】:

您能否举例说明 Rails 5 日志中缺少的信息? 【参考方案1】:

在使用 rails 5 rc1 和 puma 3.4.0 遇到同样的问题后,我发现问题与 quiet_assets gem having thread-safe issues 有关。 所以你的选择是:

设置一个环境变量RAILS_MAX_THREADS=1 以在本地只运行一个线程。 或从您的Gemfile 中删除quiet_assets 并在quiet assets be finally implemented to rails 5 之前生成一个混乱的日志。

更新

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

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

【讨论】:

老兄……你说的很对!从我的Gemfile 中删除quiet_assets 为我修复了它。日志文件很乱,现在我明白他们为什么喜欢让它安静了。但我更喜欢这样,我可以看到每个请求。【参考方案2】:

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

config.log_level = :debug

【讨论】:

我刚刚尝试过,但没有帮助。我更新了这个问题,提供了更多关于我没有看到的细节。

以上是关于如何让我的 Rails 5 日志向我显示与 Rails 4 一样的每个操作的详细信息?的主要内容,如果未能解决你的问题,请参考以下文章

如何自定义 Rails 上传表单并仍然显示已上传的文件

Rails 不生成 html.erb

如何将带有 PostCSS 清除的 Tailwind CSS 添加到 Rails 5?

Ruby on rails 5.2 - 带有活动存储的背景图像

如何使用 Rails 和 Websocket 显示更新的数据?

Rails 嵌套表单提交但不持久化数据