4

我有一个大型 Rails 应用程序，我希望提高（令人沮丧的）性能。

使用 ruby​​-prof 运行对我没有多大帮助，我得到与此类似的输出（在瘦的生产模式下运行）：

Thread ID: 9322800
Total: 1.607768
Sort by: self_time

 %self     total     self     wait    child    calls   name
 26.03      0.42     0.42     0.00     0.00     1657   Module#define_method 
  8.03      0.13     0.13     0.00     0.00      267   Set#initialize 
  4.41      0.07     0.07     0.00     0.00       44   PG::Result#values 
  4.28      0.07     0.07     0.00     0.00     1926   ActiveSupport::Callbacks::Callback#start 
  4.21      0.07     0.07     0.00     0.00    14835   Kernel#hash 
  4.13      0.08     0.07     0.00     0.01      469   Module#redefine_method 
  4.11      0.07     0.07     0.00     0.00       63  *<Class::ActiveRecord::Base>#with_scope 
  4.02      0.07     0.06     0.00     0.00      774   ActiveSupport::Callbacks::Callback#_compile_options 
  3.24      0.05     0.05     0.00     0.00       30   PG::Connection#async_exec 
  2.31      0.40     0.04     0.00     0.37     2130  *Module#class_eval 
  1.47      0.02     0.02     0.00     0.00        6   PG::Connection#unescape_bytea 
  1.03      0.05     0.02     0.00     0.03      390  *Array#select 

* indicates recursively called methods

我猜可能它在垃圾收集器上花费了很多时间，所以由于我在REE上运行，我决定尝试使用 GC.enable_stats 来获取更多信息。我将以下内容添加到我的应用程序控制器中：

around_filter :enable_gc_stats

private

def enable_gc_stats
  GC.enable_stats

  begin
    yield
  ensure
    GC.disable_stats
    GC.clear_stats
  end
end

在我的机器上以生产模式运行的一个相对较大的页面上，使用 REE 和瘦网络服务器（禁用 ruby​​-prof，因为它使它有点慢）我得到：

Completed 200 OK in 1093ms (Views: 743.1ms | ActiveRecord: 139.2ms)

GC.collections: 11
GC.time: 666299 us 666.299 ms
GC.growth: 461 KB

GC.allocated_size: 152 MB
GC.num_allocations: 1,924,773
ObjectSpace.live_objects: 1,015,195
ObjectSpace.allocated_objects: 12,393,644

因此，对于一个耗时 1093 毫秒的页面，垃圾收集器似乎花费了将近 700 毫秒。以前有人遇到过这种问题吗？我意识到你无法帮助我的应用程序（它非常大，有很多宝石和东西） - 但是有没有技术或工具可以更好地了解为什么会产生这么多垃圾？

任何想法将不胜感激！

4

1 回答 1

6

您的 rails 日志显示大部分时间 (75%) 都花在查看代码上。

您的个人资料报告显示了三个明显的热点：Module#define_method自拍时间、Module#class_eval总时间和Set#initialize.

define_method并class_eval表明可能有很多动态代码执行对我来说似乎过度 - 通常您希望尽早生成该代码并重用它，而不是重复地重新生成它。几乎可以肯定，这是您过多的对象分配问题的一部分。生成图表报告而不是平面报告应该可以帮助您找到落入这些昂贵路径的父方法，并且可以为您提供可以优化的指针。

Set#initialize可能是您的代码需要执行的真正工件，或者它可能表明存在一些重要的Set[...]或Set::new集合创建调用内联，可以执行一次并分配给常量或实例/类 var 以供重用。

ruby-prof 没问题，但您可能还想尝试perftools.rb，它很容易使用rack-perftools_profiler连接到机架导轨。perftools 有一些增强的可视化工具，可以更容易地理解热执行路径。

由于您正在运行 REE 并且广泛的对象分配（因此垃圾收集）是一个问题，您可以尝试memprof以了解所有这些分配的来源和来源。

如果您找不到减少分配对象数量的途径，您可以通过调整 GC以预分配足够大的堆以容纳典型请求的分配需求，从而以更大的进程内存大小为代价来减轻 GC 负担。Unicorn 为带外 GC提供了一个机架模块。您也许可以调整此模块的方法来处理瘦，并将所有 GC 时间转移到请求之间——您仍然需要支付 cpu 成本，但至少您不会延迟垃圾收集的响应。

于 2013-01-21T00:16:36.187 回答