记一次 Ruby 内存泄漏的排查和修复

首发 Ruby China 论坛，若是你也在学习 Ruby，不要错过这个论坛的资料。文章同步发到了公司的公众号「 春丽说」，欢迎关注。

抱歉从发朋友圈到最终文章，拖了 n 个星期。由于这几个星期也在处理其余事情，同时也一直在找最终的泄漏根源，而且指望能够修复这个问题。固然我失败了。

又一次捡起来之前的项目，既然要接手，那就准备一下升级到最新的 Rails 5.2.2 和 Ruby 新发的 2.6.1. 然而悲剧出现了，好不容易把依赖处理完了，CI 挂了，并且挂在了一个历来没有见到过的错误信息上：内存超出了 Circle CI 的限制。

查询了 Circle CI 的相关文档 circleci.com/docs/2.0/co… 发现，CircleCI 的内存限制 4GB。潜意识考虑的解决方案是增长内存。但是转眼一想，不对，由于能够肯定在我离开这个项目的时候，项目自己是好的。因此我就默默的在个人电脑上跑一下看看，而后我吃惊了。😱

我首先把怀疑是升级 Rails 致使的问题，因而开始逐步定位究竟是哪几个测试如此吃内存。好在测试并很少，逐渐缩小范围查询到了这几个测试文件的某些行。

跟朋友交流的过程当中，忽然想到了，莫非是 Ruby 2.6.1 的 bug？毕竟 Ruby 从 2.6.0 尝试引入了 JIT，保不齐在某个地方有特殊的触发条件，致使了 Ruby VM 的内存泄漏。要么咱们的代码有问题，要么第三方的代码有问题，要么 Ruby 自己的实现有问题。想到这里，整我的精神了很多，开启了满满的 debug 之路。

毕竟第一次见到活的并且能够稳定复现的内存泄漏问题，就跟路上捡到了百元大钞同样兴奋。（固然，咱们要拾金不昧，捡到了钱要交给警察蜀黎，那么捡到了 bug 固然是要修复了！）

通过简单的二分法查找，逐渐定位到了几个测试文件：

"zr_attendance/test/services/accounting_service_test.rb"

"zr_time_off/test/models/zr_time_off/request_test.rb:113#valid group days for regular hours"
"zr_time_off/test/models/zr_time_off/request_test.rb:130#valid group days for regular hours when cross weekend"
"zr_time_off/test/models/zr_time_off/request_test.rb:#"
"zr_time_off/test/models/zr_time_off/request_test.rb:#"
"zr_time_off/test/models/zr_time_off/request_test.rb:#"
复制代码

我先把出现内存泄漏的测试用例都集中到某个文件中，而后拷贝一份当前的项目目录，把版本降到 2.5.3，而后跑一遍测试。2.5.3 版本无缺，整个跑测试用例过程当中，内存稳定在 300MB 如下。

这个时候咱们能够肯定，内存泄漏问题出如今了 2.5.3 到 2.6.1 的某个版本中。这个时候，我在想，不知道这个版本是 2.5.3 到 2.6.0 仍是 2.6.0 到 2.6.1 引入的。rbenv install -l 给出的 ruby 列表，咱们能够看到从 2.5.3 到 2.6.1 之间，通过了好几个版本。因此咱们先肯定一下是 2.6.0 就引入了仍是 2.6.1 才引入，以及是否在最新的 2.7.0-dev 里面就已经解决。因而我可能须要安装四个版本的 ruby。（这纯粹是闲的）

通过几个版本，我发现 ruby 2.7.0-dev 仍然有泄漏问题，瞬间开心了不少，至少证实了这是一个必现的问题，并且是 ruby 2.6.0 引入的。那么理论上，我只要能定位到 在 ruby 2.5.3 版本工做正常的代码在新代码上会出现内存泄漏，那么经过比较两个 ruby 代码版本实现的差别，就能定位到泄漏点。我有种感受，这个泄漏点应该是来自 ruby 自己。摩拳擦掌准备深挖这个 bug！

经过测试用例，用二分法注释掉代码的笨方法，我逐渐定位到几个测试用例出错的代码行，并根据这个代码行，找到最终在实现里面出现问题的地方。固然对于用惯了 print 大法的人来讲，其实就是个体力活。

通过一段苦找，测试用例致使内存泄漏的代码被我精确到了两个点。可是由于这个项目在 2.5.3 上面跑的很是好，并且其实已经通过几个月的线上运行，咱们能够认为这个项目在咱们找到的对应业务逻辑实现的代码中是没有错误的。并且测试几个 ruby 版本的时候，咱们精确的控制了变量，Rails 版本和其余第三方 Gems 版本都一致。

因而我把代码找到，去 console 里面执行，看看 console 里面是否会一样出现内存泄漏问题。很幸运，在找到的两个测试用例调用的代码里面，我在第二个代码里面复现了内存泄漏。

因而，根据代码，咱们先从第二个点入手。第二个代码是建立一个请假记录的数据库记录，是一个标准的 Rails 实现，在执行过程当中，我发现到这一条 SQL 时候，内存就开始暴涨，因此基本能够肯定是这个问题。而另外一个代码没有在 console 里面复现，却在跑测试用例的时候出现内存泄漏。考虑了一下，应该是 development 环境对应的数据里面没有跟 worktime 相关的内容，致使没法触发下面的 SQL。

由于两个 Ruby 版本，早前的 2.5.3 是正常的，因此能够排除数据库的问题，并且咱们服务器用的是 PostgreSQL，出了 bug 也不必定会被我遇到。另外之因此发现这个问题，是由于 CircleCI 跑测试的时候，超出了 CI 限定的最大内存，因此能够证实这个问题在 Linux 和我自用的 macOS 上都有相同的问题。

一个简单的复现代码以下：

identity = ZrCore::Identity.first;
ZrTimeOff::Request.create!({
  identity: identity,
  category: :in_lieu,
  start_time: '2017-12-1 9:00'.in_time_zone('Beijing').to_time,
  end_time: '2017-12-1 18:00'.in_time_zone('Beijing').to_time,
  created_source: identity,
  status: :passed,
  unit: :halfhour,
  precision: :raw
})
复制代码

继续深究 ZrTimeOff::Request 的实现，发现只要注释掉这行代码，就不会有内存泄漏。

calculate_unit = by_day? ? 'day' : 'hour'
# send("calc_group_days_by_#{calculate_unit}")
复制代码

看样子，咱们离罪魁祸首愈来愈近了，因此我准备使用 binding.pry 在这个地方打断点。从如今看，摆在咱们前面的有两条路，一条是 ruby 的 send 方法实现改过，致使行为跟原来的不一致（后来证实想多了），另一个就是咱们经过 send 调用的两个动态方法 calc_group_days_by_day 和 calc_group_days_by_hour 的实现有问题。

经过打断点，我如今不肯定 send 方法的实现是否有问题，可是显然，当我调用 calc_group_days_by_hour 的时候，出现了内存泄漏。继续深挖 calc_group_days_by_hour 的实现。

具体细节由于涉及一些业务场景，略过一部分，经过深挖，定位到一个名为 ZrAttendance::DailyQuery 类的一个 overlap_minutes 方法。

发现，只要涉及执行 to_minutes_array 方法的地方，就会出现内存漏液，而这个方法是以前同事实现的。

class Range
  def to_minutes_array
    (self.first.to_i..self.last.to_i).step(1.minute).to_a
  end
end
复制代码

单纯从代码看，没有任何问题。如今彷佛能够肯定问题了，这个实如今 ruby 2.5.3 和 2.6.0 上表现不一致。

不过，这只是锁定了，冰山上面的部分，至于冰山下面的部分，到底为何不一致，仍然有不少地方须要深挖。

因而，咱们就能够把问题抽象成 (1512090000.. 1512122340).step(1.minute).to_a.count。

然而通过简单的分析，Range 的长度是 32340，加上 Step 以后仅仅 540 个元素，把 540 个元素转换成数组，不管如何也不至于出现内存泄漏。而按照内存最高占到数 G 大小的状况来分析，显然某个地方出现了严重的问题。

require 'active_support/all'
(1..200).step(8.seconds).to_a
复制代码

如此简单的代码在 2.6.1 就爆掉了，咱们有理由相信 Ruby 的实现出现了些许问题。

然而在找 bug 的过程当中，某天跟朋友在酒吧里面掏出电脑就是一顿讨论，在讨论的过程当中，咱们发现其实在一个月之前已经有人给 Rails 项目提出了 Issue github.com/rails/rails… ，而且 @tenderlove github.com/rails/rails… 给出了简单的修复，可是 @tenderlove 同时强调，虽然修复了，可是性能在 2.5 和 2.6 比较，2.6 慢了不少。

那么，不影响咱们继续深挖缘由。经过测试，咱们发现，

在 2.5.3 上，(1..200).step(8.seconds).class #=> Enumerator,

而在 2.6.1 版本上 (1..200).step(8.seconds).class #=> Enumerator::ArithmeticSequence。

而 Enumerator::ArithmeticSequence 这个是 2.6.0 新加的类，因此问题应该是处在这里了。那么咱们该如何界定具体问题出如今哪里呢？我想到以前参加 RubyKaigi 的时候， speakerdeck.com/watson/how-… 给出了一种能够经过 Instruments 来调试找出性能问题的方法。

经过 Call Trees，咱们能够看到，绝大多数内存都出如今了 arith_seq_each 调用的 rb_int_plus 里面，那么咱们能够判定，这个地方有什么问题致使内存出现暴涨，切必定程度下造成了内存泄漏。通过 printf 大法，我最终发现问题在于 rb_int_plus 里面的 rb_num_coerce_bin(x, y, '+');。这个方法最终会落地到： github.com/rails/rails…\

Duration.new(new_value, new_parts)
复制代码

显然，随着 arith_seq_each 的调用，这里逐渐在执行 ActiveSupport::Duration#new，我发现了一个奇怪的现象，而这个现象极有多是致使最终内存崩溃的缘由：

咱们能够看到，这里随着 arith_seq_each 咱们发现 ActiveSupport::Duration#+ 的次数会成指数型增加，而随着指数增加的结果就是内存爆掉。为啥 Enumerator 不会崩掉，由于根本就不会跑到这里嘛！而这里的问题也确实如 github.com/rails/rails… 给出的修复，而性能的问题也是出如今：rb_num_coerce_bin(x, y, '+'); 最后落地的实现上。

原本还想研究一下，而后从源头修复掉，后来发现最简单的方案就是：

(1..200).step(8.minute) #=>
(1..200).step(8.minute.to_i)
复制代码

完美！

其实这篇烂尾了，可是思前想后，仍是决定发出来，有些有趣的信息说不定能够给你们一些参考。