ActiveRecord `includes` 不在生产环境中缓存数据答案

【问题标题】：ActiveRecord `includes` not caching data in productionActiveRecord `includes` 不在生产环境中缓存数据
【发布时间】：2016-11-15 15:15:29
【问题描述】：

我正在使用带有 Heroku 的 Rails 4.2

我对 ActiveRecord 的includes 功能的理解是，它会预先获取所有相关数据，因此以后调用关系时不必进行额外的查询。

我看到它获取相关数据，但在生产中（在 Heroku 上）我也看到它每次调用关系时都会再次获取数据。为什么会这样，我该如何解决？

这只发生在生产中，而不是在开发中。

这是我观察到的函数：

  def max_outcome_scores()
    scores = Hash.new(0)
    logger.info '*** Running max_outcome_score ***'
    language_progresses.with_updates.
        includes(:progress_marker).find_each do |progress|
      scores[progress.progress_marker.topic_id] += progress.progress_marker.weight  * ProgressMarker.spread_text.keys.max
    end
    logger.info '*** Finished max_outcome_score ***'
    return scores
  end

函数按预期工作，但数据库查询过多。以下是我在日志中看到的内容：

2016-07-13T06:55:30.304893+00:00 app[web.1]: *** Running max_outcome_score ***
2016-07-13T06:55:30.308102+00:00 app[web.1]:   LanguageProgress Load (2.4ms)  SELECT  "language_progresses".* FROM "language_progresses" INNER JOIN "progress_updates" ON "progress_updates"."language_progress_id" = "language_progresses"."id" WHERE "language_progresses"."state_language_id" = $1  ORDER BY "language_progresses"."id" ASC LIMIT 1000  [["state_language_id", 209]]
2016-07-13T06:55:30.308882+00:00 app[web.1]:   ↳ app/models/state_language.rb:104:in `max_outcome_scores'
2016-07-13T06:55:30.313090+00:00 app[web.1]:   CACHE (0.0ms)  SELECT "progress_markers".* FROM "progress_markers" WHERE "progress_markers"."id" IN (70, 71, 72, 73, 74, 75, 76, 77, 78, 79, 130, 80, 81, 82, 98, 99, 100, 101, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 83, 84, 85, 86, 87, 88, 90, 91, 92, 93, 94, 131, 89, 95, 96, 97, 114, 115, 116, 117, 118, 119, 120, 121, 122, 123, 124, 125, 126, 127, 128, 129)
2016-07-13T06:55:30.314067+00:00 app[web.1]:   ↳ app/models/state_language.rb:104:in `max_outcome_scores'
2016-07-13T06:55:30.317657+00:00 app[web.1]:   CACHE (0.0ms)  SELECT  "progress_markers".* FROM "progress_markers" WHERE "progress_markers"."id" = $1 LIMIT 1  [["id", 71]]
2016-07-13T06:55:30.318379+00:00 app[web.1]:   ↳ app/models/state_language.rb:105:in `block in max_outcome_scores'
2016-07-13T06:55:30.318730+00:00 app[web.1]:   CACHE (0.0ms)  SELECT  "progress_markers".* FROM "progress_markers" WHERE "progress_markers"."id" = $1 LIMIT 1  [["id", 71]]
2016-07-13T06:55:30.319448+00:00 app[web.1]:   ↳ app/models/state_language.rb:105:in `block in max_outcome_scores'
2016-07-13T06:55:30.319872+00:00 app[web.1]:   CACHE (0.0ms)  SELECT  "progress_markers".* FROM "progress_markers" WHERE "progress_markers"."id" = $1 LIMIT 1  [["id", 75]]
2016-07-13T06:55:30.320580+00:00 app[web.1]:   ↳ app/models/state_language.rb:105:in `block in max_outcome_scores'
2016-07-13T06:55:30.320953+00:00 app[web.1]:   CACHE (0.0ms)  SELECT  "progress_markers".* FROM "progress_markers" WHERE "progress_markers"."id" = $1 LIMIT 1  [["id", 77]]
2016-07-13T06:55:30.321671+00:00 app[web.1]:   ↳ app/models/state_language.rb:105:in `block in max_outcome_scores'
2016-07-13T06:55:30.322226+00:00 app[web.1]:   CACHE (0.0ms)  SELECT  "progress_markers".* FROM "progress_markers" WHERE "progress_markers"."id" = $1 LIMIT 1  [["id", 103]]
2016-07-13T06:55:30.322938+00:00 app[web.1]:   ↳ app/models/state_language.rb:105:in `block in max_outcome_scores'
2016-07-13T06:55:30.323543+00:00 app[web.1]:   CACHE (0.0ms)  SELECT  "progress_markers".* FROM "progress_markers" WHERE "progress_markers"."id" = $1 LIMIT 1  [["id", 60]]
2016-07-13T06:55:30.324251+00:00 app[web.1]:   ↳ app/models/state_language.rb:105:in `block in max_outcome_scores'
2016-07-13T06:55:30.324966+00:00 app[web.1]: *** Finished max_outcome_score ***

我已将日志配置为在生成查询的代码中输出行。第 104 行是 includes 所在的行，第 105 行是 find-each 块内的行。

【问题讨论】：

这是否意味着它正在从缓存中获取它并花费了 0 时间？ CACHE (0.0ms)
嗯，也许吧！但是为什么它会被表示为一个 SQL 查询。看起来它正在访问数据库？
好问题 - 我也想知道答案... :D 只是它可能没有最初想象的那么糟糕...
也许 Heroku 选择绕过 ActiveRecord 的缓存并自己拦截来自 ActiveRecord 的查询。
如果您预加载记录，通常没有查询（也没有缓存查询）。你能告诉我们你的型号代码吗？

标签： ruby-on-rails caching activerecord heroku

【解决方案1】：

事实证明，即使 ActiveRecord 确实预先收集了所有必要的数据，但当它被要求提供原本需要去数据库获取的数据时，它仍然构建相关的查询，而不是点击使用它的数据库，它只是从缓存中提取数据。然后它记录它构建的查询，但没有在数据库上使用。

在某些情况下查看这些查询可能对测试和调试很有用，但大多数时候我发现它们只是阻塞了日志。

Raphael 提供了suppress this logging 的方法。将此代码放入config/initializers的ruby文件中

# Create logger that ignores messages containing “CACHE”
class CacheFreeLogger < ::Logger
  def debug(message, *args, &block)
    super unless message.include? 'CACHE'
  end
end

# Overwrite ActiveRecord’s logger
ActiveRecord::Base.logger = ActiveSupport::TaggedLogging.new(
  CacheFreeLogger.new(STDOUT)) unless Rails.env.test?

【讨论】：