为什么 ActiveSupport::JSON.encode 这么慢?

Why is ActiveSupport::JSON.encode so slow?

JRuby 9.2,Rails4.2

我一直在处理 reading/dumping 大型 JSON 对象,100+MB 的文件,这些文件通常会挂起几分钟,然后 运行 在写出它们时内存不足.

我注意到它特别发生在使用 to_json 时。下面是一个 4MB 的文件,所以它实际上是完整的:

pry(main)> f = File.open('nvdcve-1.0-recent.json'){|f| JSON.load(f) }
pry(main)> puts Benchmark.measure{ JSON.dump(f) }
  0.230000   0.010000   0.240000 (  0.081894)
=> nil
pry(main)> puts Benchmark.measure{ f.to_json }
  1.020000   0.020000   1.040000 (  0.820851)
=> nil

问题的根源在于 ActiveSupport 正在覆盖 to_json 一堆东西:

pry(main)> f.method(:to_json)
=> #<Method: Hash#to_json(to_json_with_active_support_encoder)>
pry(main)> puts Benchmark.measure{ f.to_json_without_active_support_encoder }
  0.040000   0.000000   0.040000 (  0.035408)
pry(main)> puts Benchmark.measure{ f.to_json_with_active_support_encoder }
  1.170000   0.010000   1.180000 (  0.812674)

看这里:https://apidock.com/rails/Object/to_json_with_active_support_encoder

那么 ActiveSupport::JSON.encode 与 JSON gem 的 to_json 到底有什么不同导致它慢得多,即使是在一个不起眼的 JSON 从 JSON 文件开始加载的文件?

如果我覆盖 to_json 不使用 ActiveSupport 变体,我会破坏任何 Rails 功能吗?

根据 to the source ActiveSupport::JSON 几乎只是 JSON gem 之上的附加层 - 实际上完成了大部分繁重的工作。它主要做的事情是:

转义一些在某些浏览器中可能会出现问题的额外字符。

ESCAPED_CHARS = {
            "\u2028" => '\u2028',
            "\u2029" => '\u2029',
            ">"      => '\u003e',
            "<"      => '\u003c',
            "&"      => '\u0026',
            }

评论没有说明有问题的浏览器是哪些,这对于现代浏览器来说可能完全不是问题。

将对象转换为合适的 JSON 表示:

      # Convert an object into a "JSON-ready" representation composed of
      # primitives like Hash, Array, String, Numeric,
      # and +true+/+false+/+nil+.
      # Recursively calls #as_json to the object to recursively build a
      # fully JSON-ready object.
      #
      # This allows developers to implement #as_json without having to
      # worry about what base types of objects they are allowed to return
      # or having to remember to call #as_json recursively.
      #
      # Note: the +options+ hash passed to +object.to_json+ is only passed
      # to +object.as_json+, not any of this method's recursive +#as_json+
      # calls.
      def jsonify(value)
        case value
        when String
          EscapedString.new(value)
        when Numeric, NilClass, TrueClass, FalseClass
          value.as_json
        when Hash
          Hash[value.map { |k, v| [jsonify(k), jsonify(v)] }]
        when Array
          value.map { |v| jsonify(v) }
        else
          jsonify value.as_json
        end
      end

这可能是最重要的部分,因为 #as_json 是模型如何将自己呈现为 JSON 的关键。它还处理投射日期和时间戳以及其他非基元(ActiveSupport 为这些提供 #as_json 方法)。删除它很可能会破坏很多东西。

根据您的用例,您也许可以从您的模型对象手动创建 ruby 对象(数组、散列等)并使用 JSON.generate(data) - 我不确定它会执行得更好。

tl;drActiveSupport::JSON#encode 正在做三件额外的事情。

  1. Calling as_json要求每个对象提供适合序列化的数据结构。
  2. "jsonifying" that data 到 JSON 基元和处理递归。
  3. Escaping HTML in strings.

JSON.dump决定事情会变成JSON,你无法控制。 as_json 回调允许您准确控制对象的转储方式。对于简单的对象,这会增加一些开销。对于其他一切,这都非常重要。

jsonify 使转储对象更容易。它会在大约 29% 的时间里咀嚼。

This allows developers to implement #as_json without having to worry about what base types of objects they are allowed to return or having to remember to call #as_json recursively.

转义 HTML 允许将 JSON 放入 HTML 页面。这大约是 38% 的时间。这对于咀嚼这么多时间来说是有限的。不幸的是,它不能轻易关闭。那可能是一个有价值的补丁。

只有 10% 用于真正的 JSON 编码器。这与我的基准测试结果大致一致。

[12] pry(main)> puts Benchmark.measure{ ActiveSupport::JSON.encode(h) }
  1.241299   0.009459   1.250758 (  1.253938)
=> nil
[13] pry(main)> puts Benchmark.measure{ JSON.dump(h) }
  0.117118   0.003333   0.120451 (  0.120881)

注意:这是 Ruby 2.6.3 和 Rails 5.2.3。这就是我所拥有的,旧版本的性能问题不那么有趣。你可以自己运行他们,我希望它是差不多的。

运行 这与 ruby-prof 我们可以看到 JSON.dump 将所有时间都花在了几个功能上。

$ rails -e 'require "json"; require "ruby-prof"; h = File.open("nvdcve-1.0-recent.json"){|f| JSON.load(f) }; result = RubyProf.profile { JSON.dump(h) }; printer = RubyProf::GraphPrinter.new(result); printer.print(STDOUT, {})' > json.prof
------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.275      0.134      0.000      0.141              1/1     <Module::JSON>#generate
  99.98%  48.78%      0.275      0.134      0.000      0.141                1     JSON::Ext::Generator::State#generate 
                      0.097      0.097      0.000      0.000    401143/401143     String#encode
                      0.021      0.021      0.000      0.000    101047/101047     Hash#keys
                      0.021      0.021      0.000      0.000    213358/213358     String#to_s
                      0.001      0.001      0.000      0.000        2058/2058     Float#to_s
------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.097      0.097      0.000      0.000    401143/401143     JSON::Ext::Generator::State#generate
  35.26%  35.26%      0.097      0.097      0.000      0.000           401143     String#encode                  
------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.021      0.021      0.000      0.000    101047/101047     JSON::Ext::Generator::State#generate
   7.79%   7.79%      0.021      0.021      0.000      0.000           101047     Hash#keys                      
------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.021      0.021      0.000      0.000    213358/213358     JSON::Ext::Generator::State#generate
   7.77%   7.77%      0.021      0.021      0.000      0.000           213358     String#to_s                    
------------------------------------------------------------------------------------------------------------------------------------------------------
  • 49% 实际产生 JSON。
  • 8% 遍历哈希键。
  • 35% in String#encode,大概是为了确保所有字符串都是 UTF-8 所要求的。
  • 8% 字符串化。

现在 ActiveSupport::JSON.encode(h)。出于某种原因 h.to_json 不会从命令行通过 encode,但它会在控制台中进行。

$ rails -e 'require "json"; require "ruby-prof"; h = File.open("nvdcve-1.0-recent.json"){|f| JSON.load(f) }; result = RubyProf.profile { ActiveSupport::JSON.encode(h) }; printer = RubyProf::GraphPrinter.new(result); printer.print(STDOUT, {})' > as.prof

它的配置文件比较复杂。从头开始。

------------------------------------------------------------------------------------------------------------------------------------------------------
                      3.020      0.000      0.000      3.020              1/1     <Module::ActiveSupport::JSON>#encode
  96.58%   0.00%      3.020      0.000      0.000      3.020                1     ActiveSupport::JSON::Encoding::JSONGemEncoder#encode /Users/schwern/.rvm/gems/ruby-2.6.3/gems/activesupport-5.2.3/lib/active_support/json/encoding.rb:34
                      1.483      0.000      0.000      1.483              1/1     ActiveSupport::JSON::Encoding::JSONGemEncoder#stringify
                      0.894      0.000      0.000      0.894         1/519065     ActiveSupport::JSON::Encoding::JSONGemEncoder#jsonify
                      0.643      0.000      0.000      0.643         1/101047     Hash#as_json
                      0.000      0.000      0.000      0.000         1/305710     Kernel#dup
------------------------------------------------------------------------------------------------------------------------------------------------------

它花费 95% 的时间在 ActiveSupport::JSON::Encoding::JSONGemEncoder#encode

def encode(value)
  stringify jsonify value.as_json(options.dup)
end

value.as_json 向 return 请求序列化为 JSON 的数据结构的值。这分散在不同的方法中。

这些本身并不会占用很多时间,但它们确实会递归占用总时间的 21%。

------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.634      0.009      0.000      0.625      9800/101047     Hash#each
                      0.642      0.075      0.000      0.567     91246/101047     Array#map
                      0.643      0.000      0.000      0.643         1/101047     ActiveSupport::JSON::Encoding::JSONGemEncoder#encode
  20.56%   2.69%      0.643      0.084      0.000      0.559           101047    *Hash#as_json                   /Users/schwern/.rvm/gems/ruby-2.6.3/gems/activesupport-5.2.3/lib/active_support/core_ext/object/json.rb:157
                      0.643      0.031      0.000      0.612    101047/202094     Enumerable#map
                      0.036      0.036      0.000      0.000    101047/202094     <Class::Hash>#[]
------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.643      0.003      0.000      0.639      10311/10311     Hash#each
  20.56%   0.11%      0.643      0.003      0.000      0.639            10311    *Array#as_json                  /Users/schwern/.rvm/gems/ruby-2.6.3/gems/activesupport-5.2.3/lib/active_support/core_ext/object/json.rb:151
                      0.643      0.051      0.000      0.592      10311/20623     Array#map
------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.000      0.000      0.000      0.000      1102/187785     Array#map
                      0.033      0.033      0.000      0.000    186683/187785     Hash#each
   1.05%   1.05%      0.033      0.033      0.000      0.000           187785     String#as_json                 /Users/schwern/.rvm/gems/ruby-2.6.3/gems/activesupport-5.2.3/lib/active_support/core_ext/object/json.rb:86
------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.001      0.001      0.000      0.000        2058/4116     Hash#each
                      0.001      0.001      0.000      0.000        2058/4116     ActiveSupport::JSON::Encoding::JSONGemEncoder#jsonify
   0.05%   0.04%      0.002      0.001      0.000      0.000             4116     Float#as_json                  /Users/schwern/.rvm/gems/ruby-2.6.3/gems/activesupport-5.2.3/lib/active_support/core_ext/object/json.rb:106
                      0.000      0.000      0.000      0.000        4116/4116     Float#finite?
------------------------------------------------------------------------------------------------------------------------------------------------------

jsonifyas_json 结构转换为 JSON 原语。 "This allows developers to implement #as_json without having to worry about what base types of objects they are allowed to return or having to remember to call #as_json recursively." 这占用了大约 29% 的总时间。

------------------------------------------------------------------------------------------------------------------------------------------------------
                      0.894      0.107      0.000      0.787     92348/519065     Array#map
                      0.894      0.224      0.000      0.670    426716/519065     Hash#each
                      0.894      0.000      0.000      0.894         1/519065     ActiveSupport::JSON::Encoding::JSONGemEncoder#encode
  28.60%  10.59%      0.894      0.331      0.000      0.563           519065    *ActiveSupport::JSON::Encoding::JSONGemEncoder#jsonify /Users/schwern/.rvm/gems/ruby-2.6.3/gems/activesupport-5.2.3/lib/active_support/json/encoding.rb:85
                      0.894      0.036      0.000      0.858    101047/202094     Enumerable#map
                      0.894      0.029      0.000      0.866      10311/20623     Array#map
                      0.193      0.129      0.000      0.064    401143/401153     Class#new
                      0.130      0.130      0.000      0.000  1104275/1104283     Module#===
                      0.031      0.031      0.000      0.000    101047/202094     <Class::Hash>#[]
                      0.001      0.001      0.000      0.000        2058/4116     Float#as_json
                      0.001      0.001      0.000      0.000        2533/5066     FalseClass#as_json
                      0.000      0.000      0.000      0.000        1973/3946     TrueClass#as_json
------------------------------------------------------------------------------------------------------------------------------------------------------
  • stringify 将所有这些交给 JSON.generate
------------------------------------------------------------------------------------------------------------------------------------------------------
                      1.483      0.000      0.000      1.483              1/1     ActiveSupport::JSON::Encoding::JSONGemEncoder#encode
  47.42%   0.00%      1.483      0.000      0.000      1.483                1     ActiveSupport::JSON::Encoding::JSONGemEncoder#stringify /Users/schwern/.rvm/gems/ruby-2.6.3/gems/activesupport-5.2.3/lib/active_support/json/encoding.rb:101
                      1.483      0.000      0.000      1.483              1/1     <Module::JSON>#generate
------------------------------------------------------------------------------------------------------------------------------------------------------

JSON.generate 调用 JSON::Ext::Generator::State#generate 占用了总时间的 47%。 但是38%花在了ActiveSupport::JSON::Encoding::JSONGemEncoder::EscapedString#to_json,这个方法逃逸了HTML。 这意味着实际生成 JSON 所花费的时间仅为 运行 时间的 10%。这与基准测试结果一致。

------------------------------------------------------------------------------------------------------------------------------------------------------
                      1.483      0.228      0.000      1.254              1/1     <Module::JSON>#generate
  47.42%   7.31%      1.483      0.228      0.000      1.254                1     JSON::Ext::Generator::State#generate 
                      1.176      0.271      0.000      0.905    401143/401143     ActiveSupport::JSON::Encoding::JSONGemEncoder::EscapedString#to_json
                      0.040      0.040      0.000      0.000    213358/213358     ActiveSupport::JSON::Encoding::JSONGemEncoder::EscapedString#to_s
                      0.037      0.037      0.000      0.000    101047/101047     Hash#keys
                      0.001      0.001      0.000      0.000        2058/2058     Float#to_s
------------------------------------------------------------------------------------------------------------------------------------------------------
                      1.176      0.271      0.000      0.905    401143/401143     JSON::Ext::Generator::State#generate
  37.63%   8.68%      1.176      0.271      0.000      0.905           401143     ActiveSupport::JSON::Encoding::JSONGemEncoder::EscapedString#to_json /Users/schwern/.rvm/gems/ruby-2.6.3/gems/activesupport-5.2.3/lib/active_support/json/encoding.rb:55
                      0.614      0.209      0.000      0.405    401143/401143     ActiveSupport::ToJsonWithActiveSupportEncoder#to_json
                      0.292      0.292      0.000      0.000    401143/401143     String#gsub
------------------------------------------------------------------------------------------------------------------------------------------------------```