我正在尝试分析一个相对复杂的Node.js服务器应用程序中的内存/GC问题。即使在非常适度的负载下,它也会变得不响应,并且这些暂停随时间的推移而变得越来越长。使用--trace-gc
参数运行显示极长的垃圾收集时间可能是原因:
[4805] 537 ms: Mark-sweep 17.6 (46.4) -> 10.3 (47.4) MB, 20 ms [allocation failure] [GC in old space requested].
[4805] 1338 ms: Mark-sweep 31.3 (58.4) -> 19.2 (57.2) MB, 40 ms [allocation failure] [promotion limit reached].
[4805] 2662 ms: Mark-sweep 58.0 (79.2) -> 43.9 (85.2) MB, 109 ms [Runtime::PerformGC] [promotion limit reached].
[4805] 4014 ms: Mark-sweep 90.1 (111.5) -> 70.6 (113.9) MB, 114 ms [allocation failure] [promotion limit reached].
[4805] 7283 ms: Mark-sweep 129.7 (153.9) -> 112.0 (158.9) MB, 511 ms [allocation failure] [promotion limit reached].
[4805] 10979 ms: Mark-sweep 184.6 (210.9) -> 160.3 (212.9) MB, 422 ms [Runtime::PerformGC] [promotion limit reached].
[4805] 1146869 ms: Mark-sweep 243.8 (271.4) -> 191.6 (267.9) MB, 1856 ms [allocation failure] [promotion limit reached].
[4805] 1731440 ms: Mark-sweep 282.1 (307.4) -> 197.5 (298.9) MB, 1 / 11230 ms [allocation failure] [promotion limit reached].
[4805] 2024385 ms: Mark-sweep 291.0 (320.8) -> 197.3 (306.9) MB, 9076 ms [Runtime::PerformGC] [promotion limit reached].
[4805] 2623396 ms: Mark-sweep 290.9 (317.1) -> 196.9 (311.9) MB, 1 / 15401 ms [allocation failure] [promotion limit reached].
[4805] 3223769 ms: Mark-sweep 291.4 (323.6) -> 187.8 (318.9) MB, 1 / 13385 ms [allocation failure] [promotion limit reached].
[4805] 4225777 ms: Mark-sweep 280.1 (324.2) -> 190.6 (315.9) MB, 1 / 13266 ms [allocation failure] [promotion limit reached].
[4805] 4705442 ms: Mark-sweep 286.2 (321.4) -> 195.2 (314.9) MB, 1 / 17256 ms [Runtime::PerformGC] [promotion limit reached].
[4805] 5225595 ms: Mark-sweep 288.3 (324.0) -> 201.7 (316.9) MB, 1 / 22266 ms [Runtime::PerformGC] [promotion limit reached].
[4805] 6127372 ms: Mark-sweep 296.5 (324.6) -> 200.5 (316.9) MB, 1 / 28325 ms [allocation failure] [promotion limit reached].
[4805] 6523938 ms: Mark-sweep 297.8 (328.9) -> 198.8 (323.9) MB, 1 / 27213 ms [allocation failure] [promotion limit reached].
[4805] 7355394 ms: Mark-sweep 292.1 (330.7) -> 223.9 (322.9) MB, 60202 ms [allocation failure] [promotion limit reached].
完整的 (--trace-gc-verbose
) 输出可以在这里找到。
这些日志是使用以下参数运行服务器的结果:
--expose-gc --trace-gc --trace-gc-verbose --trace-gc-ignore-scavenger --max-old-space-size=1000
随着运行时间的增长,暂停时间会变得越来越长(通常为几分钟),最终在几个小时后完全锁定。可用内存从未耗尽,而RSS甚至没有接近1000mb旧空间限制,因此似乎不是泄漏。我觉得代码中可能有一些非常不寻常的东西,使得GC无法在可接受的时间范围内完成其工作。
我的问题是:如何进一步分析这个问题,并缩小可能的原因?有什么推荐的工具可以帮助解决这类问题吗?我正在寻找一种比单纯地关闭和打开代码部分更有效的方法,这样做非常麻烦和耗时。
顺便提一下,我非常感谢任何解释GC调试输出中使用的术语/消息(如“达到提升限制”)以及列在那里的数字的文档链接。我对V8 GC的基本工作原理有一个很基本的理解(这个帮了很大的忙),但是那些输出中的大部分内容仍然超出了我的理解范围。
如果有关系的话:这是在Ubuntu 14.04 Server上运行的Node.js v0.10.33。
编辑: 一段时间以前,我们转向了io.js,在那里这个问题根本没有出现(可能是由于更近期的V8版本)。我从未找到过Node v0.10中这个问题的原因,更不用说解决方法了。