Ruby on Rails - 缓慢加载并在垃圾回收器中花费大量时间

Question

Ruby on Rails - 缓慢加载并在垃圾回收器中花费大量时间

ruby-on-railsrubygarbage-collectionprofiling

5

我有一个大型的Rails应用程序，我想要提高（糟糕的）性能。

使用ruby-prof运行并没有帮助我很多，我得到的输出类似于这个（在thin上以生产模式运行）：

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和thin web服务器（由于它会使运行速度变慢，因此禁用了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毫秒是在垃圾回收器中消耗的。有人遇到过这种问题吗？我知道你不能特别帮助我的应用程序（它非常庞大，并且有很多宝石和其他东西）-但是否有技术或工具可以更好地了解为什么会创建那么多垃圾？

任何想法都会非常感激！

- maxpenguin

1个回答

网页内容由stack overflow 提供, 点击上面的

可以查看英文原文，
原文链接

- dbenhur · Accepted Answer

您的 Rails 日志显示，大部分时间（75%）都花在视图代码上。

您的性能报告显示了三个明显的热点：Module#define_method 的自我时间，Module#class_eval 的总时间和 Set#initialize。 define_method 和 class_eval 表明可能有大量动态代码执行，这似乎对我来说过度了--通常情况下，您希望尽早生成该代码并重用它，而不是反复重新生成它。它几乎肯定是您过度对象分配问题的一部分。生成图形报告而不是扁平报告应该可以帮助您找到落入这些昂贵路径的父方法，并为您提供指针以进行优化。 Set#initialize 可能是代码需要执行的真正结果，或者这可能是一个迹象，表明行内存在一些重要的 Set[...] 或 Set::new 集合创建调用，可以仅执行一次并分配给常量或实例/类变量以供重用。

ruby-prof还不错，但你可能也想尝试一下perftools.rb，它很容易与rack-perftools_profiler连接到Rack Rails上。Perftools有一些增强的可视化工具，可以使热执行路径更容易理解。

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

如果您找不到减少分配对象数量的路径，可以通过调整GC来预先分配足够大的堆来缓解GC负担，但会增加进程的内存占用。Unicorn提供了一个用于带外GC的Rack模块。您可以尝试使用该模块的方法来适应thin并将所有GC时间移到请求之间--仍需支付CPU成本，但至少不会延迟垃圾回收响应。