ruby Rails ActiveRecord：：LogSubscriber不输出详细查询日志

h9vpoimq  于 12个月前  发布在  Ruby
关注(0)|答案(2)|浏览(96)

我尝试在Rails中启用详细查询日志记录，但ActiveRecord::LogSubscriber的行为很奇怪，这导致详细查询日志记录无法工作。
问题似乎起源于此：https://github.com/rails/rails/blob/v6.0.0/activerecord/lib/active_record/log_subscriber.rb#L113
如果我inspectlocations变量，我可以看到它 * 确实 * 有内容：

[
  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activerecord-6.0.0/lib/active_record/log_subscriber.rb:100:in `debug'",
  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activerecord-6.0.0/lib/active_record/log_subscriber.rb:45:in `sql'",
  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/subscriber.rb:145:in `finish'",
  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/log_subscriber.rb:107:in `finish'",
  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/notifications/fanout.rb:160:in `finish'",
  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/notifications/fanout.rb:62:in `block in finish'",
  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/notifications/fanout.rb:62:in `each'",
  ...
]

但是一旦它通过了clean方法，它就是一个空数组。所以这个：

backtrace_cleaner.clean(locations.lazy).first

返回nil。因此，第105行上的source赋值为nil，这意味着第107行上的if source的计算结果为false，并且不记录任何内容。

更新

我将这两个puts添加到ActiveRecord::LogSubscriber中：

def log_query_source
  source = extract_query_source_location(caller)

  puts "-----\n-\n-\nCALLERS: #{caller.inspect}\n-\n-\n-----"

  if source
    logger.debug("  ↳ #{source}")
  end
end

def extract_query_source_location(locations)
  puts "-----\n-\n-\nCLEANER: #{backtrace_cleaner.instance_values}\n-\n-\n-----"

  backtrace_cleaner.clean(locations.lazy).first
end

以帮助收集一些上下文，了解实际注册为调用者的内容以及回溯清理器为过滤和静默建立的内容。
下面是调用者的输出（我只包含了足够的内容，以显示在我们的应用程序中列出了源代码）：

[
  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activerecord-6.0.0/lib/active_record/log_subscriber.rb:100:in `debug'",
  
  ...

  "/Users/jeff/Development/lead-simple/LeadSimple/components/api/app/graph/api/loaders/association_loader.rb:47:in `preload_association'",
  "/Users/jeff/Development/lead-simple/LeadSimple/components/api/app/graph/api/loaders/association_loader.rb:34:in `perform'",

  ...

  "/Users/jeff/Development/lead-simple/LeadSimple/components/api/app/controllers/api/graphql_controller.rb:16:in `execute'",

  ...

  "/Users/jeff/Development/lead-simple/LeadSimple/components/api/lib/api/graphql_reloader.rb:18:in `call'",

  ...

  "/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/puma-5.6.5/lib/puma/thread_pool.rb:147:in `block in spawn_thread'"
]

下面是回溯清理器的输出：

{
  "silencers"=>[
    #<Proc:0x0000000108343330@/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/backtrace_cleaner.rb:101>, 
    #<Proc:0x00000001083432e0@/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/backtrace_cleaner.rb:105>, 
    #<Proc:0x00000001083431c8@/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/railties-6.0.0/lib/rails/backtrace_cleaner.rb:19>
  ], 
  "filters"=>[
    #<Proc:0x0000000108343380@/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.0/lib/active_support/backtrace_cleaner.rb:97>, 
    #<Proc:0x0000000108343240@/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/railties-6.0.0/lib/rails/backtrace_cleaner.rb:16>, 
    #<Proc:0x0000000108343218@/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/railties-6.0.0/lib/rails/backtrace_cleaner.rb:17>, 
    #<Proc:0x00000001083431f0@/Users/jeff/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/railties-6.0.0/lib/rails/backtrace_cleaner.rb:18>
  ], 
  "root"=>"/Users/jeff/Development/lead-simple/LeadSimple/"
}

正如您所看到的，没有任何特定于我们的应用程序代码的内容被静默（甚至过滤）。然而，有一个"root"示例值，这非常奇怪，因为如果你查看ActiveRecord::BacktraceCleaner的source code，唯一定义的示例变量是@filters和@silencers。
我猜这里涉及到了这一点，因为设置为"root"值的路径将删除我们的应用程序级跟踪（如果用作消音器）。问题是我不知道这是从哪里来的。
我唯一能猜到的是，我们的一个gem是重载ActiveSupport::BacktraceCleaner来添加@root示例变量和一些基于此的额外沉默层。//

ruby

2条答案

按热度按时间
hi3rlvi2

hi3rlvi21#

Rails控制台始终禁用详细日志记录

您是否通过查看Rails服务器正在记录的内容或Rails控制台中的活动来测试详细日志记录？此行将始终关闭控制台中执行的活动的详细查询日志记录：

# ActiveRecord::Railtie
console do |app|
  require "active_record/railties/console_sandbox" if app.sandbox?
  require "active_record/base"
  unless ActiveSupport::Logger.logger_outputs_to?(Rails.logger, STDERR, STDOUT)
    console = ActiveSupport::Logger.new(STDERR)
    Rails.logger.extend ActiveSupport::Logger.broadcast console
  end
  ActiveRecord::Base.verbose_query_logs = false  # <--- HERE
end

Here's the commit that added that line。提交消息提供了更多详细信息并引用回this issue。这是故意的，是为了减少Rails控制台中的噪音。
如果你想在Rails控制台中重新打开详细日志记录，你必须手动重置标志：

ActiveRecord::Base.verbose_query_logs = true

或者你可以在应用的初始化器中添加这个，以便在控制台启动时打开它：

# config/initializers/verbose_logging.rb
Rails.application.console do
  ActiveRecord::Base.verbose_query_logs = true
end

请注意，Rails指南建议不要在生产环境中启用此功能，因为会占用内存，因此您可能希望在该环境中关闭此功能，具体取决于运行生产控制台的可用资源。

在日志记录前清理回溯

当进行详细日志记录时，Rails将尝试删除标准Ruby代码引用和gem引用，以便显示应用程序中的源代码位置。这是使用ActiveRecord::LogSubscriber.backtrace_cleaner中的清理器完成的，默认情况下，它是从ActiveSupport::BacktraceCleaner继承的Rails::BacktraceCleaner。
要测试Rails::BacktraceCleaner是否意外地清理了您的代码，您可以执行以下操作：

# Get the source location for a class method somewhere in your app
path = MyClass.method(:my_class_method).source_location.first

# Run it through the BacktraceCleaner
backtrace_cleaner = Rails::BacktraceCleaner.new
backtrace_cleaner.clean([path])

如果返回[]，您可能需要检查是否将应用代码放在RbConfig::CONFIG["rubylibdir"]文件夹中。BacktraceCleaner将假定那里的代码是标准Ruby库的一部分，并将其从回溯中删除。
Rails::BacktraceCleaner还排除了在app、config、lib或test子目录中找不到的代码。在这里完成了。
你的root说：

/Users/jeff/Development/lead-simple/LeadSimple/

下面的子文件夹是：

/Users/jeff/Development/lead-simple/LeadSimple/components/...

Rails会将其从回溯中清除。您可以使用以下内容进行检查：

test = ['/Users/jeff/Development/lead-simple/LeadSimple/components/api/app/graph/api/loaders/association_loader.rb']
backtrace_cleaner = Rails::BacktraceCleaner.new

# Filtering will drop off everything before the root
filtered = backtrace_cleaner.send(:filter_backtrace, [path])
 => ["components/api/app/graph/api/loaders/association_loader.rb"]

# Silencing will drop off paths that don't start with app, config, lib, or test
backtrace_cleaner.send(:silence, filtered)
 => []

要避免这种情况，您可以：

  • 将代码组织到不同的子文件夹中，或者
  • Rails::BacktraceCleaner，或
  • 在初始化器中重新定义Rails::BacktraceCleaner::APP_DIRS_PATTERN

最后一个选项是最简单的，但在应用程序启动时会抛出already initialized constant错误。

赞(0）分享  回复(0）举报  12个月前
zzoitvuj

zzoitvuj2#

感谢@cschroed给了我所需要的答案。
只是想贴出我自己的答案，以及显示我如何充分实现这一点：
config/initializers/verbose_sql_logging.rb

if Rails.env.development? && ENV['VERBOSE_SQL_LOGGING']&.downcase == 'true'
  # NOTE: As of Rails 7, this will need to be set using `ActiveRecord.verbose_query_logs=`.
  ActiveRecord::Base.verbose_query_logs = true

  # NOTE: This is required because of our `components/` directory. By default, Rails will silence
  # any path that doesn't start with "app", "config", "lib", or "test".
  #
  # Reference:
  #   https://github.com/rails/rails/blob/v6.0.0/railties/lib/rails/backtrace_cleaner.rb#L7
  #   https://github.com/rails/rails/blob/v6.0.0/railties/lib/rails/backtrace_cleaner.rb#L19
  Rails::BacktraceCleaner::APP_DIRS_PATTERN = Regexp.new(
    Rails::BacktraceCleaner::APP_DIRS_PATTERN.to_s.gsub('app|', 'app|components|')
  )

  ActiveRecord::Base.logger = ActiveSupport::Logger.new($stdout)
end

我之所以使用gsub将components目录注入到正则表达式模式中，而不是将常量重新分配给不同的正则表达式字面量，是因为Rails 7中的模式略有不同（与我们目前使用的Rails 6.0.0相比）。

**Rails 6.0.0：**https：github.com/rails/rails/blob/v6.0.0/railties/lib/rails/backtrace_cleaner.rb#L7
**Rails 7：**https：github.com/rails/rails/blob/main/railties/lib/rails/backtrace_cleaner.rb#L8

正如您所看到的，基本逻辑仍然相同，这将允许gsub继续正常工作，但我假设逻辑只是更严格一点。通过修改Rails已经定义的内容，而不是从头开始重新分配，这意味着如果/当我们升级到Rails 7时，我们将能够利用正则表达式模式的更新，而不必修改我们的初始化器。

赞(0）分享  回复(0）举报  12个月前
我来回答

相关问题

    查看更多

    热门标签

    更多
    JavaquerypythonNode开发语言requestUtil数据库Table后端算法LoggerMessageElementParser

    最新问答

    更多
    • 蜀ICP备2022004421号-2 NULL123 https://www.null123.com © All rights reserved
    • 本站内容来源互联网,如果侵犯您的权益请联系我们删除, 联系方式：448109455@qq.com