寻找Ruby内存泄漏的原因

60

我在我的Rails代码中发现了一个内存泄漏 - 也就是说,我找到了哪段代码泄漏了,但不知道它为什么会泄漏。我已经简化了它,变成了一个不需要Rails的测试用例:

require 'csspool'
require 'ruby-mass'

def report
    puts 'Memory ' + `ps ax -o pid,rss | grep -E "^[[:space:]]*#{$$}"`.strip.split.map(&:to_i)[1].to_s + 'KB'
    Mass.print
end

report

# note I do not store the return value here
CSSPool::CSS::Document.parse(File.new('/home/jason/big.css'))

ObjectSpace.garbage_collect
sleep 1

report
ruby-mass 可以让我看到内存中的所有对象。 CSSPool 是一个基于racc的CSS解析器。 /home/jason/big.css是一个1.5MB的CSS文件

输出结果如下:

Memory 9264KB

==================================================
 Objects within [] namespace
==================================================
  String: 7261
  RubyVM::InstructionSequence: 1151
  Array: 562
  Class: 313
  Regexp: 181
  Proc: 111
  Encoding: 99
  Gem::StubSpecification: 66
  Gem::StubSpecification::StubLine: 60
  Gem::Version: 60
  Module: 31
  Hash: 29
  Gem::Requirement: 25
  RubyVM::Env: 11
  Gem::Specification: 8
  Float: 7
  Gem::Dependency: 7
  Range: 4
  Bignum: 3
  IO: 3
  Mutex: 3
  Time: 3
  Object: 2
  ARGF.class: 1
  Binding: 1
  Complex: 1
  Data: 1
  Gem::PathSupport: 1
  IOError: 1
  MatchData: 1
  Monitor: 1
  NoMemoryError: 1
  Process::Status: 1
  Random: 1
  RubyVM: 1
  SystemStackError: 1
  Thread: 1
  ThreadGroup: 1
  fatal: 1
==================================================

Memory 258860KB

==================================================
 Objects within [] namespace
==================================================
  String: 7456
  RubyVM::InstructionSequence: 1151
  Array: 564
  Class: 313
  Regexp: 181
  Proc: 113
  Encoding: 99
  Gem::StubSpecification: 66
  Gem::StubSpecification::StubLine: 60
  Gem::Version: 60
  Module: 31
  Hash: 30
  Gem::Requirement: 25
  RubyVM::Env: 13
  Gem::Specification: 8
  Float: 7
  Gem::Dependency: 7
  Range: 4
  Bignum: 3
  IO: 3
  Mutex: 3
  Time: 3
  Object: 2
  ARGF.class: 1
  Binding: 1
  Complex: 1
  Data: 1
  Gem::PathSupport: 1
  IOError: 1
  MatchData: 1
  Monitor: 1
  NoMemoryError: 1
  Process::Status: 1
  Random: 1
  RubyVM: 1
  SystemStackError: 1
  Thread: 1
  ThreadGroup: 1
  fatal: 1
==================================================

你可以看到内存急剧增加,一些计数器上升,但没有特定于CSSPool的对象出现。我使用ruby-mass的“index”方法来检查具有参考引用的对象,如下所示:

Mass.index.each do |k,v|
    v.each do |id|
        refs = Mass.references(Mass[id])
        puts refs if !refs.empty?
    end
end

但是,这并没有给我任何与CSSPool相关的内容,只有宝石信息之类的东西。

我还尝试了输出“GC.stat”...

puts GC.stat
CSSPool::CSS::Document.parse(File.new('/home/jason/big.css'))
ObjectSpace.garbage_collect
sleep 1
puts GC.stat

结果:

{:count=>4, :heap_used=>126, :heap_length=>138, :heap_increment=>12, :heap_live_num=>50924, :heap_free_num=>24595, :heap_final_num=>0, :total_allocated_object=>86030, :total_freed_object=>35106}
{:count=>16, :heap_used=>6039, :heap_length=>12933, :heap_increment=>3841, :heap_live_num=>13369, :heap_free_num=>2443302, :heap_final_num=>0, :total_allocated_object=>3771675, :total_freed_object=>3758306}

据我理解,如果一个对象没有被引用且垃圾回收发生了,那么该对象应该从内存中清除。但这似乎不是这里所发生的情况。

我也读过关于C级内存泄漏的文章,并且由于CSSPool使用Racc,而Racc使用C代码,因此我认为这是一个可能性。我已经通过Valgrind对我的代码进行了运行:

valgrind --partial-loads-ok=yes --undef-value-errors=no --leak-check=full --fullpath-after= ruby leak.rb 2> valgrind.txt

结果在这里。我不确定这是否确认了 C 级泄漏,因为我也读到 Ruby 对内存的处理方式 Valgrind 无法理解。

使用的版本:

  • Ruby 2.0.0-p247(我的 Rails 应用程序运行的版本)
  • Ruby 1.9.3-p392-ref(用于使用 ruby-mass 进行测试)
  • ruby-mass 0.1.3
  • CSSPool 4.0.0从这里下载
  • CentOS 6.4 和 Ubuntu 13.10

我在我的机器上使用1.9.3.x重现了相同的问题。你使用的是哪个版本? - Joe Edgar
我已经在问题中添加了版本信息。 - jb_314
4个回答

42

看起来你正在进入The Lost World。我认为问题也不在于racc中的c绑定。

Ruby内存管理既优雅又繁琐。它将对象(称为RVALUE)存储在大小约为16KB的所谓堆中。在低级别上,RVALUE是一个c结构,其中包含不同标准Ruby对象表示的union

因此,堆存储RVALUE对象,其大小不超过40字节。对于StringArrayHash等对象,这意味着小对象可以适合在堆中,但一旦它们达到阈值,Ruby堆之外的额外内存将被分配。

这个额外的内存是灵活的;一旦一个对象成为垃圾回收(GC)'ed,它就会被释放。这就是为什么你的big_string测试用例显示了内存上下行为的原因:

def report
  puts 'Memory ' + `ps ax -o pid,rss | grep -E "^[[:space:]]*#{$$}"`
          .strip.split.map(&:to_i)[1].to_s + 'KB'
end
report
big_var = " " * 10000000
report
big_var = nil 
report
ObjectSpace.garbage_collect
sleep 1
report
# ⇒ Memory 11788KB
# ⇒ Memory 65188KB
# ⇒ Memory 65188KB
# ⇒ Memory 11788KB

但是堆(参见 GC[:heap_length])自己不会在获取后释放回操作系统。看,我会对你的测试案例进行一些平淡无奇的更改:

- big_var = " " * 10000000
+ big_var = 1_000_000.times.map(&:to_s)

完成了,就这样:

# ⇒ Memory 11788KB
# ⇒ Memory 65188KB
# ⇒ Memory 65188KB
# ⇒ Memory 57448KB

现在不再将内存释放回操作系统,因为我引入的数组的每个元素都适合RVALUE大小并存储在Ruby堆中。

如果您在运行GC后检查 GC.stat 的输出,您会发现 GC [:heap_used] 值如预期般减少。 Ruby现在有许多空闲的堆,已准备好使用。

总之: 我认为c代码没有泄漏。 我认为问题出在你css中巨大图像的base64表示方式上。 我不知道解析器内部发生了什么,但看起来巨大字符串强制Ruby堆计数增加。

希望有所帮助。


我想我需要更深入地研究解析器,看看能否找到导致这种行为的代码部分,并且是否可以重写它以避免这种情况,因为似乎没有办法让 Ruby 不这样做。你因为提供了一个演示问题的小测试用例并给了我一个寻找问题的思路而获得了赏金。 - jb_314
很高兴能够帮忙。我也浏览了解析器代码。我建议你从csspool/lib/csspool/visitors/to_css.rb中的escape_css_*方法开始研究。有一些可疑的调用使用了带有代码块的gsub。如果我没记错的话,它会在Ruby堆中分配一个|char|块变量,而你CSS文件中的背景大约有1M个字符。 - Aleksei Matiushkin
@mudasobwa 这是否意味着任何长时间运行的使用小变量(因此使用 RVALUEs)的 Ruby 进程都会随着时间增长而增大?我有点想不通。你能指出任何官方(或补充)文档吗? - YWCA Hello
@YWCAHello 不,它并不意味着任何进程都会增长其大小。经过垃圾回收的RValues会返回到Ruby内存管理器中。仅当没有更多的空闲插槽可用时,即进程试图同时创建大量的RValues(例如通过一次处理具有不同唯一小值的外部CSV,而不是批量处理)时,才从OS请求新内存。在正常情况下,它将重复使用已经经过垃圾回收的插槽。请搜索“Ruby RValue memory management”或查看Ruby源代码([tag:C])以获取详细信息。 - Aleksei Matiushkin

15

好的,我找到了答案。我保留另一个回答,因为那些信息很难收集,但与此问题有关,它可能会帮助其他人搜索相关问题。

然而,你的问题似乎是由于Ruby实际上并没有将内存释放回操作系统导致的。

内存分配

虽然Ruby程序员通常不必担心内存分配,但有时可能会出现以下问题:

即使在清除了所有大对象的引用后,我的Ruby进程仍然保持如此之大。 我确定GC已经运行了几次并释放了我的大对象,并且我没有泄漏内存。

C程序员可能会问同样的问题:

我释放了很多内存,为什么我的进程仍然这么大?

从内核分配到用户空间的内存更容易以大块方式进行,因此用户空间通过自己做更多的工作来避免与内核交互。

用户空间库/运行时实现了内存分配器(例如:libc中的malloc(3)),它从内核中获取大块内存,并将其分成小片段供用户空间应用程序使用。

因此,在用户空间需要向内核请求更多内存之前,可能会发生多个用户空间内存分配。 因此,如果您从内核中获得了一大块内存,并且只使用了其中的一小部分,则该大块内存仍然保持分配状态。

将内存释放回内核也需要成本。 用户空间内存分配器可能会将该内存(私有地)保留下来,希望它可以在同一进程内被重复使用,而不是将其返还给内核供其他进程使用。 (Ruby最佳实践)

因此,您的对象很可能已被垃圾回收并释放回Ruby可用内存,但由于Ruby从不向操作系统返回未使用的内存,因此即使进行垃圾回收后,进程的rss值仍然保持不变。实际上,这是有意设计出来的。根据Mike Perham的说法:

...... 由于MRI从不返还未使用的内存,我们的守护程序在只使用100-200MB时很容易占用300-400MB。

需要注意的是,这基本上是有意设计的。 Ruby的历史大部分上是作为文本处理命令行工具,因此它重视快速启动和小内存占用。 它没有专门为长时间运行的守护进程/服务器进程而设计。 Java在其客户端和服务器VM中也做出了类似的权衡。


1
一个简单的测试表明Ruby确实会释放内存(至少在rss值测量方面)。运行以下代码(请原谅缺乏空格):def report; puts 'Memory ' + \ps ax -o pid,rss | grep -E "^[[:space:]]*#{$$}"`.strip.split.map(&:to_i)[1].to_s + 'KB'; end; report; big_var = " " * 10000000; report; big_var = nil; report; ObjectSpace.garbage_collect; sleep 1; report`;结果是:Memory 7132KB Memory 17100KB Memory 17100KB Memory 7340KB - jb_314
你使用的操作系统是什么? - Joe Edgar
Ubuntu 13.10用于开发,CentOS 6.4用于生产。我在两者上看到了big_var测试的类似结果 - 在变量被解除引用并运行GC后,RSS会回落。 - jb_314
抱歉,我最近有些忙。我计划在有机会时在我的Ubuntu 12.04机器上进行测试,以查看它是否与Ruby和操作系统如何协同工作有关。无论如何,我仍然认为,如果它在销毁后仍然返回big_var对象,那么它应该会返回CSSPool::CSS:Document对象。实际的C代码中可能存在内存泄漏(在其顶层中使用了用C编写的Racc::Parser)。由于一些不一致的行为以及垃圾收集器缺乏信息文档,因此很难跟踪。 - Joe Edgar
我很感谢你迄今为止所做的研究。我考虑了C级漏洞的可能性。如果确实是这样,我想知道如何确认它,以便我可以将其传递给RACC团队。我已经对我的测试运行了Valgrind,并编辑了问题,以包括结果,但我不确定如何解释它。 - jb_314
显示剩余2条评论

10

在 @mudasobwa 的解释基础上,我最终找到了原因。CSSPool中的代码正在检查非常长的数据URI中的转义序列。它会使用与转义序列或单个字符匹配的正则表达式调用URI上的scanmap这些结果以进行反转义,然后将其join回字符串。这实际上为URI中的每个字符分配了一个字符串。我对此进行了修改,用gsub替换了转义序列,这似乎具有相同的结果(所有测试都通过了),并且大大减少了最终所用的内存。

使用与最初发布的测试案例相同的测试案例(除了Mass.print输出),这是更改之前的结果:

Memory 12404KB
Memory 292516KB

这是更改后的结果:

Memory 12236KB
Memory 19584KB

10
周年纪念日的答案? ;) - TK-421

9
这可能是由于Ruby 1.9.3及以上版本中的“Lazy Sweeping”功能所致。
懒惰清除基本上意味着在垃圾收集期间,Ruby只会“清除”足够的对象以为需要创建的新对象腾出空间。它这样做是因为当Ruby垃圾收集器运行时,没有其他东西在运行。这被称为“停止世界”的垃圾收集。
实质上,懒惰清除减少了 Ruby 需要“停止世界”的时间。你可以在这里阅读更多关于懒惰清除的信息here
你的RUBY_GC_MALLOC_LIMIT环境变量是什么样子的?
这里是Sam Saffron's blog的摘录,内容涉及惰性清除和RUBY_GC_MALLOC_LIMIT:
Ruby 2.0中的GC有两种不同的模式。我们有一个“完整”GC,它在分配超过malloc_limit后运行,以及一个惰性清除(部分GC),如果堆中没有空闲插槽,则会运行该GC。
惰性清除所需时间比完整GC少,但仅执行部分GC。其目标是更频繁地执行短暂GC,从而增加总吞吐量。世界停止了,但时间更短。
malloc_limit的默认设置为8MB,您可以通过将RUBY_GC_MALLOC_LIMIT设置得更高来提高它。
你的RUBY_GC_MALLOC_LIMIT非常高吗?我的设置为100000000(100MB)。默认值约为8MB,但对于Rails应用程序,他们建议将其设置得更高。如果你的设置太高,它可能会阻止Ruby删除垃圾对象,因为它认为有足够的空间可以使用。

我没有修改过那个设置,但我想可能是被其他东西设置了。我该如何检查它? - jb_314
我已修改问题,包括您链接中提到的“GC.stat”的输出。 - jb_314
如果您更改了RUBY_GC_MALLOC_LIMIT,您很可能会知道它(除非有人为您设置了机器)。您可以通过在命令行中键入echo $RUBY_GC_MALLOC_LIMIT来查看是否手动设置。如果它没有返回值,则可能设置为默认值8mb。我会继续思考这个问题。 - Joe Edgar
是的,我已经尝试了echo $RUBY_GC_MALLOC_LIMIT但没有结果,所以我想可能是我在错误的位置找。另外,关于你说的lazy vs full GC,我的生产应用程序在遇到这个问题时会消耗服务器上的所有内存,直到进程被杀死,所以我认为此时Ruby会尽力获取更多的内存。 - jb_314
在 Ruby 2.0,MacOS 上,执行 ObjectSpace.garbage_collectbig_var = " " * 100000000; big_var = nil 后没有任何作用。如果再加一个 0,它就会起作用(从 1GB 降至 5MB)。 - Nakilon

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接