Rails 记录一次排查 Puma 内存占用过高的问题

lyfi2003 for 深圳市百分之八十网络技术有限公司 · 2018年03月14日 · 最后由 wakasa 回复于 2018年04月08日 · 5385 次阅读
本帖已被设为精华帖!

这几天上线一个 Rails 系统( 采用 rails-template 标准配置 ), 每分钟访问量在 500 ~ 1500 之间, 但经常 puma 内存就上到 8G 以上, 导致系统无法响应.

经过这两天的排查处理, 现将思路整理如下, 分享出来.

现象

ruby 版本: 2.3.1

puma 版本: 3.10.0

puma 配置: 4workers, 每个 worker 8~16核, 数据库连接池 50

刚启动每个 puma worker 会申请 VSIZE 1.5G 左右, 实际占用内存(RSS) 100M, 然后在每分钟 500 用户访问下, 占用内存会迅速到 1G 以上.

22:30分

23:10分

第二天下午13:30分

现象一: 就算用户量下来, 内存占用也不会下降.

现象二: 更多的每分钟用户访问, 例如提高到 1000, 占用内存会继续提高到 2G, 还会不断上涨至 3G. 这样, 内存就会爆掉, 导致系统无响应.

现象三: postgres 连接数会有 40 个左右, 占用 5G 左右.

目标

为什么内存占用这么高, 是否有内存泄漏.

每分钟用户数与内存占用之间的关系, 是否可以优化 puma 的配置参数.

处理说明

思路一: 代码是否有内存泄漏

通读所有控制器与模型逻辑, 排查所有引用关系, 并无发现引用变量不断开的情况.

思路二: 是否与 puma 和 ruby 版本有关( 由于稳定性考虑的关系, 并未更新至最新版本 )

考虑以下控制器代码

class HomeController < ApplicationController
  def index
     @a = '0' * 1024 * 1024 * 1000
  end
end

每次请求占用 100m 内存, 但正常来说, 响应后应该释放.

测试一: 使用 puma3.10.0 和 ruby2.3.1, 进行 wrk 的压测.

wrk -c 100 -d 30 -t 5 http://perf.80percent.io/ 导致 puma 吃满内存

测试二: 使用 puma3.13.1(目前最新版) 和 ruby2.3.1, 进行 wrk 的压测.

wrk -c 100 -d 30 -t 5 http://perf.80percent.io/ 导致 puma 吃满内存

测试三: 使用 puma3.13.1 和 ruby2.4.3, 进行 wrk 的压测.

wrk -c 100 -d 30 -t 5 http://perf.80percent.io/ 导致 puma 吃满内存

结果: 与版本无关

思路三: 是否是由 puma 本身导致的内存占用问题吗?

研读 puma 官方指导, 调整 puma 的相关参数, 尤其是 workers 与 threads 配置, 并进行 wrksiege 性能压测.

模拟实现一个请求时长 200ms, 消耗内存 100m 的接口, 同时对其进行压测.

再切换至 unicorn( 另一个 rails 生态下成熟的 web 容器 )进行对照测试.

结果发现就算给到 16G 内存的机器, 这样的接口也会让并发测试将内存吃满, 不需要泄漏就有问题. puma 也不会主动释放其已经占用的系统内存.( unicorn 也类似 )

Running 30s test @ http://perf.80percent.io/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   349.22ms  416.64ms   2.00s    85.27%
    Req/Sec    52.77     42.76   370.00     68.15%
  7081 requests in 30.06s, 47.07MB read
  Socket errors: connect 0, read 10, write 0, timeout 247
Requests/sec:    235.56
Transfer/sec:      1.57MB

结论

最后, 将 api 占用过高内存的问题解决后, 整个 puma 内存占用问题就不存在了.

puma 和 unicorn 都不会主动降低操作系统内存占用, 但会复用已经申请过的内存. 所以会随着每分钟请求量的增加导致内存不断上升. 如果超出某个极限, 则有可能导致内存爆掉. 可以考虑使用 puma_worker_killer 进行控制.

并发能力与每次处理用户请求所消耗的内存和响应时间成强正关系. 本次的调查根因在于单次响应消耗内存过高导致内存不足.

额外发现, puma 的并发能力比 unicorn 强约 5 倍以上能力, 而内存消耗两者相差无几.

经测试, puma 的配置建议是 N 核 N workers, 线程配置为 8~16, 测试的性能已经比较满意.

希望本文对大家有所帮助. 有好的建议也欢迎提出交流.

共收到 30 条回复

你一个接口要消耗 100M 内存?做了什么事情,载入大文件么?

GC 的机制,你请求结束以后,内存是不会立刻释放的,要等 GC 触发。如果 GC 触发以后还没回收,那就是可能有内存泄漏。

huacnlee 回复

100M内存,是楼主在压力测试接口中 故意申请的

def index
  @a = '0' * 1024 * 1024 * 1000
end

请问Rails版本是什么?

我来实际试试,确实是之前的应用没有发现这样的情况,一些跑了好几个月的应用,内存最终都是稳定在一个位置的。

huacnlee 回复

@ceclinux-github Rails 5.1.4

@huacnlee 看上去是保持在 puma 顶峰并发时的占用内存不释放, 原因暂不清楚. 而且就算请求结束了, 新请求也有可能由于内存不足而失败. 有时候不会复用原有的内存.

Terry.Shi 关于 RoR 内存问题的讨论 中提及了此贴 03月14日 17:31

做了个例子,在 Linux 上 Rails 5.2,Ruby 2.5, Puma 以及 production 环境。

配置:

  • Ubuntu
  • Rails 5.2 + Ruby 2.5 + production env
  • Puma 3.11 + 1 worker, 5 threads

结果

并发 (10 并) 用工具跑一段时间观察内存

  • 每次 100M,最后内存稳定在 560M 左右,不会变动
  • 每次 10M,最后内存稳定在 300M 左右
  • 什么都不做,最后内存稳定在 80M,无论跑多久
huacnlee 回复

➜  perf_test git:(master) wrk -c 10 -d 30 -t 1 http://perf.80percent.io/
Running 30s test @ http://perf.80percent.io/
  1 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.11s    56.29ms   1.49s    91.39%
    Req/Sec    17.09     12.86    50.00     54.70%
  267 requests in 30.04s, 1.48MB read
Requests/sec:      8.89
Transfer/sec:     50.55KB

每次请求 100m 内存, 执行下面这个测试( 10 并发, 30秒 ), 结果是上面的情况, 会一直稳定这个内存占用.

puma 配置

[18270] Puma starting in cluster mode... [18270] * Version 3.11.3 (ruby 2.3.1-p112), codename: Love Song [18270] * Min threads: 4, max threads: 8

我刚才调整了一下配置,Puma 单线程跑,每次请求 100m 内存

环境:

  • Docker 内的 Ubuntu 14.04 64bit
  • Ruby 2.5, Rails 5.2.0.rc1, Puma 3.11.3
  • 无任何 Ruby GC 配置
  • 最简单的 Controller
class WelcomeController < ApplicationController
  # GET /
  def index
    foo = '0' * 1024 * 1024 * 100
    memory = `ps -o rss= -p #{$$}`.to_i
    render plain: "hello, #{memory / 1024}MB\n #{GC.stat} \n"
  end

  # GET /gc
  # 手动调用 GC.start
  def gc
    GC.start
    memory = `ps -o rss= -p #{$$}`.to_i
    render plain: "hello, #{memory / 1024}MB\n #{GC.stat} \n"
  end
end

单线程测试

Puma starting in single mode...
* Version 3.11.3 (ruby 2.5.0-p0), codename: Love Song
* Min threads: 1, max threads: 1
* Environment: production
* Daemonizing...

并发跑下去,最后稳定在 279M

/gc 里面有个手动的 GC.start

$ siege -c 100 http://localhost:3000/
$ curl http://localhost:3000/
hello, 279M
$ curl http://localhost:3000/
hello, 178MB
$ curl http://localhost:3000/gc
hello, 78MB
$  curl http://localhost:3000/
hello, 178MB
$ curl http://localhost:3000/gc
hello, 78MB

调整为 5 个 threads

Puma starting in single mode...
* Version 3.11.3 (ruby 2.5.0-p0), codename: Love Song
* Min threads: 5, max threads: 5
* Environment: production
* Daemonizing...

结果:

$ curl http://localhost:3000/
hello, 783MB
$ curl http://localhost:3000/gc
hello, 78MB
$ curl http://localhost:3000/
hello, 178MB
$ curl http://localhost:3000/
hello, 279MB
$ curl http://localhost:3000/
hello, 178MB
$ curl http://localhost:3000/gc
hello, 78MB

以上测试说明,这是能正确回收的

10楼 已删除
lyfi2003 回复

你用 Linux 试试,我刚才又在 macOS 上验证了一下

GET /gcGC.start)不会释放,内存还是 GET / 后的样子,单线程 100M 的场景,最后固定在 473MB

huacnlee 回复

我一直是跑在 Ubuntu 14.04 上的.

刚按你的补充测试了一下, 如果是单进程模式, 跑 GC.start 是会逐步释放内存. 但每一次好像只释放 100m.

如果是多进程模式, 释放是只针对当前响应请求的进程. 看起来只是处理的线程有释放内存.

如果不明确 GC.start 则没有释放内存的迹象.

结论还是以文章最后的总结为准, 不明确 GC.start 会保持最大响应请求并发的内存.

huacnlee 回复

补充了一些信息, 还需要再有一些观察.

lyfi2003 回复

不是啊 我验证的结果确实是每次调用 GC.start 内存一定能回收降低到 79M 的。

多进程下你调用 GET /gc 回收的只是其中一个进程。

huacnlee 将本帖设为了精华贴 03月14日 19:52

https://ruby-china.org/topics/25584 可以参考下这篇文章,针对ruby的内存分配与回收做了很好的解释。

puma.conf 贴一下看看呗,preload_app! 有关系吗

huacnlee 回复

这是咱们昨天晚饭讨论时候测试的内存占用, 现在我再次截图, 还是保持原有的内存占用.

victor 回复

preload 不影响这个,搞出来的都是局部变量

preload 是 copy on write 在有改变全局变量的时候,copy 到 worker 里面,否则和 master 共享在启动是载入的内容

我曾经也遇到过这个问题,

ruby 的gc 我是这么理解的

每次内存使用完毕后,会标记为 可释放,但是什么时候释放,就得看ruby 的gc 和操作系统的释放条件了 我记得在某篇文章记得ruby 启动有个参数可以控制gc 的启动条件, 也可以在编译ruby的时候写进去

ps 假设一次消耗100M 按照题主的puma 配置: 4workers, 每个 worker 8~16核 跑满就需要 4 * 16 * 100M = 6.4G, 但是puma 我当时选择的是worker 的工作方式,回收threads 是要靠主线程的, 当主线程认为压力过大的时候,worker threads是来不及销毁的,直接拿来处理下一条

如果是4 cpus / 8G 内存,就刚好够用, 但是如果这台机器跑了其他的东西,比如db, redis 啥的,估计服务就挂了

我遇到的实际情况是

每台机器本身访问量在 1000rpm 之后我们有个黑白名单,名单本身不小,大概 2w条,这些数据不稳定,易变. 之后写入的数据要过这个名单,过一次加上七七八八的计算,要2秒. 一个访问就消耗20M 左右的内存,,但是这种过滤操作本身量不多 之后puma 就占了1.5 G, 2 cpus/4G 运行个1-2 小时,服务器内存就到85%, 当时研究了好久,最后发现puma 开的threads min 和max 都设置的30.

后来一算 觉得thread似乎很不合理,网站大部分数据是在30ms 之内就请求完的, 其实我平均每个访问控制在100ms,10 个threads 在每个worker下, 这样2 workers 我就可以承受 6000rpm的访问, 之后我就修改了 threads 成为 min 5 max 15, killer 设置成 1.5 G 内存, 90% 启用, 基本很少看到killer 运行

jicheng1014 回复

按你的说法来看, 这个 GC 不太对, 一天都没跑一次. Ruby 是用 rbenv 标准选项进行的编译.

jicheng1014 回复

是不是就是说threads开的越多,占用的内存就会越多,但是内存并不是无限上涨,还是受threads数量的限制

Terry.Shi 回复

thread 也是会回收的

jicheng1014 回复

就是说在代码稳定,没有泄露的情况下,并发量一定的时候,内存占用其实是一个稳定的状态。只是说这个稳定的值可能对于机器配置来说是偏高的?

jicheng1014 回复

你确定?

然而 puma 是 react 模型,轮询线程池是 loop,只有服务器挂了、退出了才会回收。。。

其实 我早期就发现了 Ruby 这个问题,我想要是 Ruby 跟 JVM 一样有一个 -XX:max 的最大内存设置就好了。

不仅仅是 puma、unicorn,我自己的 amber-kit 也会这样的。。。midori 也会

跟 Server 没关系,Ruby 的 GC 分代回收,有些常驻的对象没那么容易直接收回去滴,项目大了,controller model 各种 obj 多了,如果在一段时间这么多的东西都会需要,就不轻易回收。

思考一下 Ruby 的内存池要是碰到缓存攻击(别人故意去搜索命中率低的东西)那样的事情。。。

幸好 unicorn 有杀进程的机制


补充:

刚看到一个帖子

https://samsaffron.com/archive/2014/04/08/ruby-2-1-garbage-collection-ready-for-production

We can tune our settings, from “Ruby 2.1 Out-of-Band GC”:

RUBY_GC_MALLOC_LIMIT: (default: 16MB)
RUBY_GC_MALLOC_LIMIT_MAX: (default: 32MB)
RUBY_GC_MALLOC_LIMIT_GROWTH_FACTOR: (default: 1.4x)

and

RUBY_GC_OLDMALLOC_LIMIT: (default: 16MB)
RUBY_GC_OLDMALLOC_LIMIT_MAX: (default: 128MB)
RUBY_GC_OLDMALLOC_LIMIT_GROWTH_FACTOR: (default: 1.2x)

这应该很有帮助,设置试试看

可能是内存碎片导致, 这篇文章讨论了类似的问题,并有相应的解决方案 https://www.speedshop.co/2017/12/04/malloc-doubles-ruby-memory.html

jakit 回复

Out-of-Band GC 2.2 之后就不再需要了

42thcoder 回复

它是有 Out-of-Band,有些时候我故意读一些大文件(比如大软件安装包)测试过,其实是过一段时间会 GC,回到一个稳定的位置,但是有时候感觉起来不太起作用,真正跑 site 的场景,GC 不会在测试场景那么轻松,因为请求是那么的频繁和密集还有离散的。

所以个人观点觉得要么就分流,不同的实例跑网站不同的部分。但是网站架构就改了,最简洁的办法,还是进程突破 max 触手工强 GC 或者 kill,或者限定 max,这样来得直接。

jakit 回复

哦? 那我理解的 puma 的 threads 配置似乎是有问题了 有个 min max 同时我也看到了有些情况数据库连接突然的减少和增多 我还以为是回收和释放了呢

jakit 回复

我跟你的观点基本一致, puma 不会轻易做 GC, 是会保持最大并发时需要的内存状态的. 跟大家交流收获很大, 其他朋友可以继续参与讨论交流.

puma配置的worker、线程数其实是不能太大的。worker数等于核心数,最大线程数等于4倍于核心数就已经很多了。如果并发比较均匀,最小和最大线程数可以保持一致。虽然线程数增加是有利于几乎都在等阻塞IO的应用,但是内存会受不了,等完阻塞IO的GIL竞争也会很严重。所以一般worker数 = 核心数。保守一点,例如机器还跑数据库之类的,也可以核心数减去1、2,留点资源给他们。最小最大线程数都锁在 核心数 * 2 (或者最小是核心数,最大是2倍核心数)会更加合适一些。头铁,对内存占用有自信的话,可以4倍。买服务器的时候都买2核4GB,不够用了,就多买一台,做负载均衡(注意国内云的内网速度)。

其实先不提Ruby的GC有没有锅, puma是有bug可能导致内存溢出的。例如3.x http1.1 persistent连接溢出。但是代码没有严格控制风格,现在已经很乱了,找个bug很费劲。另外MRI也没有像JProfiler那么好的性能调优工具,找起来几乎靠片面的数据去直觉推断,挺麻烦的。如果真要用puma,弄个nginx在puma前面挡一下,可能可以改善一点。如果应用并发比较高,还是建议上passenger, unicorn这些有商业背景的(并发模型也很耿直的)。 虽然损失了一堆并发,但是长期运行的话,会稳一点。:)

zhaoyshine Puma 突然 CPU 占用 99%+ 中提及了此贴 05月04日 10:25
需要 登录 后方可回复, 如果你还没有账号请点击这里 注册