Table of Contents

1. 前言

本文是系列文章Node.JS Profile的一部分,完整的文章列表请去总章查看。

本文是Node内存相关文章的其中一篇,主要负责深度解析V8引擎GC相关的技术。

2. GC日志

Node的V8引擎支持使用命令行添加option启动的形式,在stdout中输出GC相关内容的日志。GC日志基本上可以说是了解V8 GC行为及状态的唯一方法。

2.1 日志启用

GC日志需要在命令行启动node的时候添加option来启用,相关的option我找到一个不错的gist,里面有描述,这里fork了下:

而本文撰写时参照的Node版本,支持的GC相关option如下:

2.2 如何Runtime触发GC

如果想要在runtime使用代码主动触发GC,则需要在node启动的时候添加option--expose-gc

然后在代码里:

if (global.gc) {
    global.gc();
}

2.3 常用GC options输出效果范例

范例效果:

2.4 GC日志图解

范例中的图片来自:Are your v8 garbage collection logs speaking to you?Joyee Cheung -Alibaba Cloud(Alibaba Group)

options

--trace_gc

--trace_gc_nvp

--trace_gc_verbose

3. GC日志解析工具

3.1 aliyun-node/v8-gc-log-parser

阿里的一个GC日志解析工具,可以在命令行下运行,也可以在代码runtime里运行。该工具的主要作用是将node --trace_gc输出的内容进行可读化解析,输出成JSON格式,方便后续存储或分析。

当前版本支持的options有:

  • --trace_gc
  • --trace_gc_nvp
  • --trace_gc_verbose

该工具的最大优势就是内容完全按v8官方输出的来,没有作者主观性的内容增删,仅只是辅助阅读。

缺点是gc的日志输出就在stdout里,如果stdout还有点别的什么正常业务输出,分析起来就麻烦了,先要过滤一次,否则该工具用不了。

3.2 dainis/node-gcstats

第三方的GC信息工具,使用C++编写,作为node的addone运行,只能在代码runtime里运行。输出的内容和官方gc日志的内容不尽相同,相对来说更简洁,适合需要简单功能的用户使用。

优势在于可以在运行时直接获取gc信息(GC时触发监听事件),方便在代码里直接存储到其他地方,事后进行分析。

缺点是输出信息不如官方的gc日志那么详细和多样性。

3.3 marcominetti/node-memwatch

第三方的GC信息工具,使用C++编写,作为node的addone运行,只能在代码runtime里运行。这个工具关注的不仅仅只是GC,有几个功能有点意思:

  • 监听GC事件,并给出简单报告,功能比较类似dainis/node-gcstats
  • 监听最近5次GC,持续内存上涨则触发一个内存泄露的监听事件;可以和heapdump配合,监听到leak则导出heapdump
  • HeapDiff,用来对比并计算出两次堆快照的差异,意义不大

更详细的介绍可以看这篇:Node.js 性能调优之内存篇(三)——memwatch-next

优点基本同上面的那个工具,且可以判断leak(其实自己也可以实现)。

缺点是功能相对来说意义不是很大,输出的内容信息不足。

3.4 阿里工具的辅助脚本

aliyun-node/v8-gc-log-parser只支持事后解析静态日志文件并输出结果,但有的时候我们需要查看下实时的情况。这里有一个脚本可以使用:

该脚本暂时不能分析--trace-gc --trace-gc-verbose的输出结果,因为该输出是多行的,需要聚合后才可以发给解析工具。有兴趣的可以自己改造下。

4. NVP日志详解

在V8官方输出的GC日志当中,--trace_gc--trace_gc_verbose输出的内容都是比较简单的,主要给出了非常实用的:

  • gc类型
  • 暂停时间
  • 对象数量变化
  • 内存用量变化

这些信息基本上能满足大部分的使用情况。

--trace_gc_nvp这个option输出的信息则不同,相对于上述的两个option,nvp日志给出的内容相当详细,而且根据GC的类型不同,输出的内容也不尽相同。是用来进行GC细节调优时候非常重要的信息来源。

但可惜的是网上并没有很详细的,针对这个类型输出日志内容的解释,无论是官方的还是社区的。因此最后的手段就是阅读V8的源代码查找里面的信息细节。本文会在当前的章节段落中,将阅读源码获取的解释记录在下面,方便读者查阅。

当然这里会查找源码去寻求解释的也只是一部分比较有价值的内容,并非全部,如果读者有兴趣可以自行查阅源码,下面会给出源码信息。

4.1 源码阅读指引

行文使用的Node V8版本信息:

$ node -e “console.log(process.versions.v8)”
6.0.286.52

因此这里使用的V8分支是:6.0.286

源码主要是V8的:heap.ccgc-tracer.cc,这两个文件。

gc-tracer.h其实很简单,只是一些显示和输出之类的,主要的逻辑和统计还是在heap.h里。

几个结构和逻辑入口:

heap.h

gc-tracer.h

gc-tracer.cc

global-handles.h

global-handles.cc

4.2 Event::SCAVENGER

  • pause:GC暂停时长,单位ms
  • mutator:计算公式;关于什么是mutator,见这里
  • gc:GC类型字符串,这里肯定是s
  • reduce_memory:只是一个布尔值的flag(Memory reduction flag set. ),见定义赋值
  • heap.*:不同Scope的耗时(Amounts of time spent in different scopes during GC.);见定义使用
  • scavenge:类似上面的heap.*,按scope分的耗时:Scope::SCAVENGER_SCAVENGE(新生代)
  • evacuate:类似上面的heap.*,按scope分的耗时:Scope::SCAVENGER_EVACUATE(新生代)
  • old_new:类似上面的heap.*,按scope分的耗时:Scope::SCAVENGER_OLD_TO_NEW_POINTERS(新生代)
  • weak:类似上面的heap.*,按scope分的耗时:Scope::SCAVENGER_WEAK(新生代)
  • roots:类似上面的heap.*,按scope分的耗时:Scope::SCAVENGER_ROOTS(新生代)
  • code:类似上面的heap.*,按scope分的耗时:Scope::SCAVENGER_CODE_FLUSH_CANDIDATES(新生代)
  • semispace:类似上面的heap.*,按scope分的耗时:Scope::SCAVENGER_SEMISPACE(新生代)
  • steps_count:增量标记步骤数,见代码(老生代,MC是指Mark & Compact)
  • steps_took: 增量标记步骤,见代码(老生代,MC是指Mark & Compact)
  • scavenge_throughput
  • total_size_before:GC开始时的对象内存大小 bytes(Size of objects in heap set in constructor.),start_object_size
  • total_size_after:GC结束时的对象内存大小 bytes(Size of objects in heap set in destructor.),end_object_size
  • holes_size_before
    • Total amount of space either wasted or contained in one of free lists before the current GC.
    • 直译的意思是:当前GC开始之前被标记为浪费掉的处于可用freelist内的内存空间大小 bytes
    • 乍看这两者的貌似是相反的概念,但仔细阅读后感觉这里的hole的概念并非一般论的内存空洞,而应该理解为因GC导致的内存空间不连贯
    • 这在执行Compacting的时候会起到判断的作用:Compacting >> 主要发生在某一页中死亡对象留下来的空洞(hole)比较多的时候
    • start_holes_size
  • holes_size_after
    • Total amount of space either wasted or contained in one of free lists after the current GC.
    • end_holes_size
  • allocated:自上次GC结束到这次GC开始之间的时间里,分配的内存大小 bytes,见赋值
  • promoted:晋升的对象内存大小 bytes,见定义getter
  • semi_space_copied:新生代内存空间对半拷贝的对象内存大小 bytes,见定义getter
  • nodes_died_in_new:源码中针对这里的Node说明很模糊,不清楚是不是内存页的意思,源码可以见Node定义new_space_nodes_
  • nodes_copied_in_new:同上
  • nodes_promoted:同上
  • promotion_ratio
  • average_survival_ratio:新生代对象平均生存率,计算见方法定义
  • promotion_rate
  • semi_space_copy_rate
  • new_space_allocation_throughput:
  • context_disposal_rate:不太理解,计算见方法定义

4.3 Event::MINOR_MARK_COMPACTOR

  • pause
  • mutator
  • gc:mmc
  • reduce_memory
  • minor_mc:Scope::MINOR_MC
  • finish_sweeping:Scope::MINOR_MC_SWEEPING
  • mark:Scope::MINOR_MC_MARK
  • mark.identify_global_handles:Scope::MINOR_MC_MARK_IDENTIFY_GLOBAL_HANDLES
  • mark.seed:Scope::MINOR_MC_MARK_SEED
  • mark.roots:Scope::MINOR_MC_MARK_ROOTS
  • mark.weak:Scope::MINOR_MC_MARK_WEAK
  • mark.global_handles:Scope::MINOR_MC_MARK_GLOBAL_HANDLES
  • clear:Scope::MINOR_MC_CLEAR
  • clear.string_table:Scope::MINOR_MC_CLEAR_STRING_TABLE
  • clear.weak_lists:Scope::MINOR_MC_CLEAR_WEAK_LISTS
  • evacuate:Scope::MINOR_MC_EVACUATE
  • evacuate.copy:Scope::MINOR_MC_EVACUATE_COPY
  • evacuate.update_pointers:Scope::MINOR_MC_EVACUATE_UPDATE_POINTERS
  • evacuate.update_pointers.to_new:Scope::MINOR_MC_EVACUATE_UPDATE_POINTERS_TO_NEW
  • evacuate.update_pointers.to_new.tospace:Scope::MINOR_MC_EVACUATE_UPDATE_POINTERS_TO_NEW_TOSPACE
  • evacuate.update_pointers.to_new.roots:Scope::MINOR_MC_EVACUATE_UPDATE_POINTERS_TO_NEW_ROOTS
  • evacuate.update_pointers.to_new.old:Scope::MINOR_MC_EVACUATE_UPDATE_POINTERS_TO_NEW_OLD
  • update_marking_deque:Scope::MINOR_MC_MARKING_DEQUE
  • reset_liveness:Scope::MINOR_MC_RESET_LIVENESS

reduce_memory都和上面的意义相同,之后的全部都是按scope分的耗时。

4.4 Event::MARK_COMPACTOR & Event::INCREMENTAL_MARK_COMPACTOR

  • pause
  • mutator
  • gc:ms
  • reduce_memory
  • heap.prologue:Scope::HEAP_PROLOGUE
  • heap.epilogue:Scope::HEAP_EPILOGUE
  • heap.epilogue.reduce_new_space:Scope::HEAP_EPILOGUE_REDUCE_NEW_SPACE
  • heap.external.prologue:Scope::HEAP_EXTERNAL_PROLOGUE
  • heap.external.epilogue:Scope::HEAP_EXTERNAL_EPILOGUE
  • heap.external.weak_global_handles:Scope::HEAP_EXTERNAL_WEAK_GLOBAL_HANDLES
  • clear:Scope::MC_CLEAR
  • clear.code_flush:Scope::MC_CLEAR_CODE_FLUSH
  • clear.dependent_code:Scope::MC_CLEAR_DEPENDENT_CODE
  • clear.maps:Scope::MC_CLEAR_MAPS
  • clear.slots_buffer:Scope::MC_CLEAR_SLOTS_BUFFER
  • clear.store_buffer:Scope::MC_CLEAR_STORE_BUFFER
  • clear.string_table:Scope::MC_CLEAR_STRING_TABLE
  • clear.weak_cells:Scope::MC_CLEAR_WEAK_CELLS
  • clear.weak_collections:Scope::MC_CLEAR_WEAK_COLLECTIONS
  • clear.weak_lists:Scope::MC_CLEAR_WEAK_LISTS
  • epilogue:Scope::MC_EPILOGUE
  • evacuate:Scope::MC_EVACUATE
  • evacuate.candidates:Scope::MC_EVACUATE_CANDIDATES
  • evacuate.clean_up:Scope::MC_EVACUATE_CLEAN_UP
  • evacuate.copy:Scope::MC_EVACUATE_COPY
  • evacuate.prologue:Scope::MC_EVACUATE_PROLOGUE
  • evacuate.epilogue:Scope::MC_EVACUATE_EPILOGUE
  • evacuate.rebalance:Scope::MC_EVACUATE_REBALANCE
  • evacuate.update_pointers:Scope::MC_EVACUATE_UPDATE_POINTERS
  • evacuate.update_pointers.to_evacuated:Scope::MC_EVACUATE_UPDATE_POINTERS_TO_EVACUATED
  • evacuate.update_pointers.to_new:Scope::MC_EVACUATE_UPDATE_POINTERS_TO_NEW
  • evacuate.update_pointers.weak:Scope::MC_EVACUATE_UPDATE_POINTERS_WEAK
  • finish:Scope::MC_FINISH
  • mark:Scope::MC_MARK
  • mark.finish_incremental:Scope::MC_MARK_FINISH_INCREMENTAL
  • mark.prepare_code_flush:Scope::MC_MARK_PREPARE_CODE_FLUSH
  • mark.roots:Scope::MC_MARK_ROOTS
  • mark.weak_closure:Scope::MC_MARK_WEAK_CLOSURE
  • mark.weak_closure.ephemeral:Scope::MC_MARK_WEAK_CLOSURE_EPHEMERAL
  • mark.weak_closure.weak_handles:Scope::MC_MARK_WEAK_CLOSURE_WEAK_HANDLES
  • mark.weak_closure.weak_roots:Scope::MC_MARK_WEAK_CLOSURE_WEAK_ROOTS
  • mark.weak_closure.harmony:Scope::MC_MARK_WEAK_CLOSURE_HARMONY
  • mark.wrapper_prologue:Scope::MC_MARK_WRAPPER_PROLOGUE
  • mark.wrapper_epilogue:Scope::MC_MARK_WRAPPER_EPILOGUE
  • mark.wrapper_tracing:Scope::MC_MARK_WRAPPER_TRACING
  • prologue:Scope::MC_PROLOGUE
  • sweep:Scope::MC_SWEEP
  • sweep.code:Scope::MC_SWEEP_CODE
  • sweep.map:Scope::MC_SWEEP_MAP
  • sweep.old:Scope::MC_SWEEP_OLD
  • incremental:Scope::MC_INCREMENTAL
  • incremental.finalize:Scope::MC_INCREMENTAL_FINALIZE
  • incremental.finalize.body:Scope::MC_INCREMENTAL_FINALIZE_BODY
  • incremental.finalize.external.prologue:Scope::MC_INCREMENTAL_EXTERNAL_PROLOGUE
  • incremental.finalize.external.epilogue:Scope::MC_INCREMENTAL_EXTERNAL_EPILOGUE
  • incremental.sweeping:Scope::MC_INCREMENTAL_SWEEPING
  • incremental.wrapper_prologue:Scope::MC_INCREMENTAL_WRAPPER_PROLOGUE
  • incremental.wrapper_tracing:Scope::MC_INCREMENTAL_WRAPPER_TRACING
  • incremental_wrapper_tracing_longest_step:incremental_marking_scopes[Scope::MC_INCREMENTAL_WRAPPER_TRACING].longest_step
  • incremental_finalize_longest_step:incremental_marking_scopes[Scope::MC_INCREMENTAL_FINALIZE_BODY].longest_step
  • incremental_finalize_steps_count:incremental_marking_scopes[Scope::MC_INCREMENTAL_FINALIZE_BODY].steps
  • incremental_longest_step:incremental_marking_scopes[Scope::MC_INCREMENTAL].longest_step
  • incremental_steps_count:incremental_marking_scopes[Scope::MC_INCREMENTAL].steps
  • incremental_marking_throughput:增量标记速率 bytes/ms,代码见方法定义
  • incremental_walltime_duration:增量标记总耗时 ms
  • total_size_before:见4.2里的相同解释
  • total_size_after:见4.2里的相同解释
  • holes_size_before:见4.2里的相同解释
  • holes_size_after:见4.2里的相同解释
  • allocated:见4.2里的相同解释
  • promoted:见4.2里的相同解释
  • semi_space_copied:见4.2里的相同解释
  • nodes_died_in_new:见4.2里的相同解释
  • nodes_copied_in_new:见4.2里的相同解释
  • nodes_promoted:见4.2里的相同解释
  • promotion_ratio:见4.2里的相同解释
  • average_survival_ratio:见4.2里的相同解释
  • promotion_rate:见4.2里的相同解释
  • semi_space_copy_rate:见4.2里的相同解释
  • new_space_allocation_throughput:见4.2里的相同解释
  • context_disposal_rate:见4.2里的相同解释
  • compaction_speed:compacting的平均速度,bytes/ms,计算见方法定义

reduce_memory下面的一大段老样子,都是按scope分的耗时。

5. 资料

EOF