hyj1991_个人页_阿里云开发者社区

发表了文章 2020-01-22

逆工程 JS 对象 (一): 浅谈 V8 对象布局

本文首发于 Github，仓库地址: https://github.com/hyj1991/sourcecode_notes，里面也有更多和本文的相关其它内容，欢迎关注。逆工程 JS 对象 (一): 浅谈 V8 对象布局逆工程 JS 对象其实就是根据 V8 设计的对 JS 对象存储结构的描述，开发者可以实现在进程运行内存空间中或者进程崩溃后的 Core 文件还原的内存空间中来反推出当前 JS 代码运行状态和 JS 对象在堆空间的分配状况的一种技术。这种技术可以帮助开发者分析运行中的 JS 程序，或者根据 JS 程序崩溃生成的 Core 文件来进行事后的崩溃原因分析，本文主要从 V8 对象布局的角度来和大家探讨学习下逆工程背后的一些知识。 I. 伪指针 (Tagged Pointer) 我们先来介绍认识一种特殊类型的指针: Tagged Pointer，这里虽然说是特殊，其实从存储或者占用空间大小来说并没有什么特别的地方: 32 位操作系统: 4 byte 32 bit 64 位操作系统: 8 byte 64 bit 我们可以看到，如果程序被设计为按照 4 byte 或者 8 byte 地址对齐来实现最佳的运行效率，那么指针的最后 2 位 (32 位操作系统) 或者 3 位 (64 位操作系统) 下一定都是 0，这样某种程度上对于昂贵的内存空间来说是一种浪费。 Tagged Pointer 就是利用指针最后相同的几位来实现将传统指针区分为不同数据类型的一种历史悠久的实现，具体到 V8 引擎中，它将最后一位 (bit) 通过 0 或者 1 来区分要将当前的指针解析为小整形 (Smi) 或者一个常规的指针: 最后一位为 0: 小整形 (Smi) 最后一位为 1: 指向堆对象的常规指针 (需要转换) 实际上 V8 中对 Smi Tag 的描述在 include/v8-internal.h 中: // Tag information for Smi. const int kSmiTag = 0; const int kSmiTagSize = 1; const intptr_t kSmiTagMask = (1 << kSmiTagSize) - 1; 这里和上文的描述是吻合的。其实引擎之所以这样处理，是因为在 ECMA 规范中，JS 中所有的 Number 类型数据都是被描述要基于 IEEE-754 双精度浮点型，而我们都知道，CPU 操作浮点数的效率远低于整数，而开发者对于整数的使用又是一个非常普遍的需求: 比如循环计数控制或者数组下标索引等，因此为了程序执行效率的提升引擎需要将一定范围内的整数直接将原始指针进行转换后读取。 II. 小整形 (Small Integer) 上面一小节中其实也提到，Tagged Pointer 只能用来描述一定范围内的整数大小，那么这个范围具体是多大呢，我们可以继续来从源码中找到答案。在 include/v8-internal.h 中，首先通过模板定义了 32 位操作系统下的 Smi Tag 信息: // Smi constants for systems where tagged pointer is a 32-bit value. template <> struct SmiTagging<4> { enum { kSmiShiftSize = 0, kSmiValueSize = 31 }; static constexpr intptr_t kSmiMinValue = static_cast<intptr_t>(kUintptrAllBitsSet << (kSmiValueSize - 1)); static constexpr intptr_t kSmiMaxValue = -(kSmiMinValue + 1); }; 这里很显然，32 位操作系统下的 Tagged Pointer，去掉最后一位的标记位，因此用来表示 Smi 值只有 32 位，所以 kSmiValueSize 为 31。下面的部分则是计算此时能表示的最大整数: 2^(31 - 1) - 1 = 1073741823 (有符号)，所以 32 位下 Smi 的表示范围为: -1073741823 ~ 1073741823。接着看下64 位操作系统下的 Smi Tag 信息: // Smi constants for systems where tagged pointer is a 64-bit value. template <> struct SmiTagging<8> { enum { kSmiShiftSize = 31, kSmiValueSize = 32 }; }; 同样的部分就补贴了，这里可以看到 Smi 的范围增加了一位，所以表示的范围也增加到: -2147483647 ~ 2147483647。当然有意思的是 V8 引擎为了某些场景下需要跨平台程序完全一致性也提供了一个宏 V8_31BIT_SMIS_ON_64BIT_ARCH: #ifdef V8_31BIT_SMIS_ON_64BIT_ARCH using PlatformSmiTagging = SmiTagging<kApiInt32Size>; #else using PlatformSmiTagging = SmiTagging<kApiTaggedSize>; #endif 如果定义了这个宏的话，则在 64 位操作系统下会使用和 32 位操作系统下范围完全一致的 Smi。有了上面的知识，还原给定的一个内存空间地址 p 对应的 Smi 值就很简单了，首先根据掩码判断 p 是否为 Smi: bool Smi::Check(int64_t p) const { return (p & kSmiTagMask) == kSmiTag; } 如果是 Smi，则将地址右移 kSmiShiftSize + kSmiTagMask 位得到记录的原始 int 值: int64_t Smi::GetValue(int64_t p) const { return p >> (kSmiShiftSize + kSmiTagMask); } 这样就完成了将一个实际保存了 Smi 的 Tagged Pointer 逆工程为其原始保存的 int 值的过程。 III. 堆对象 (Heap Object) 上一小节中实现的 Smi::Check 方法可以对给定的地址 p 来判断其最终存储 / 指向的是 Smi 还是一个 V8 对象，kSmiTag 目前在引擎中值为 0，显然当 p 的最后一位为 1 时 Check 方法返回 false，这里就意味着所有的值为奇数的地址实际都指向一个 V8 对象，我们也可以称之为 Heap Object。如果开发同学曾经因为 JS 的内存问题在 Node.js 或者浏览器中导出过堆快照，并且在 Chrome devtools 中解析，那么就会发现所有的以 @ 符号开始对象地址都是奇数，这里也从侧面印证了这一论述。对于这个给定的奇数地址 p，我们要将其逆工程回真正指向的 Heap Object 会复杂一些，我们来看下如何处理。 V8 基于自己的规则实现了一套对象布局方式，用 OOP 的方式来描述，所有的 JS 对象类型布局全部都继承自 Heap Object 的布局方式，其实这个也很好理解，毕竟所有 JS 对象本身就是从 Heap Object 派生出来的。我们先来看下引擎对 Heap Object 的布局描述: // src/objects/heap-object.h // Layout description. #define HEAP_OBJECT_FIELDS(V) \ V(kMapOffset, kTaggedSize) \ /* Header size. */ \ V(kHeaderSize, 0) DEFINE_FIELD_OFFSET_CONSTANTS(Object::kHeaderSize, HEAP_OBJECT_FIELDS) #undef HEAP_OBJECT_FIELDS 其中 DEFINE_FIELD_OFFSET_CONSTANTS 宏是一个用来定义枚举类型的宏，其定义为: // src/utils/utils.h #define DEFINE_FIELD_OFFSET_CONSTANTS(StartOffset, LIST_MACRO) \ enum { \ LIST_MACRO##_StartOffset = StartOffset - 1, \ LIST_MACRO(DEFINE_ONE_FIELD_OFFSET) \ }; 里面的 DEFINE_ONE_FIELD_OFFSET 宏定义为: // src/utils/utils.h #define DEFINE_ONE_FIELD_OFFSET(Name, Size) Name, Name##End = Name + (Size)-1, 宏嵌套宏看起来比较复杂，但是其实它们的本质还是减少重复代码的编写，这里我们直接将 Heap Object 的布局定义宏全部展开: enum { HEAP_OBJECT_FIELDS_StartOffset = Object::kHeaderSize - 1, kMapOffset, kMapOffsetEnd = kMapOffset + (kTaggedSize)-1, kHeaderSize, kHeaderSizeEnd = kHeaderSize + (0) - 1, }; 这样就很清晰了，可以看到宏展开后就是一个描述布局方式的枚举，这里 Heap Object 的布局接在 Object 之后，它的核心只定义了一个指向 Map 的伪指针。伪指针定义可以参见 Tagged Pointer，它的大小和系统的指针大小完全一致，32 位系统上为 4 byte，64 位系统上为 8 byte。 :::warning MetaMap这里的 Map 和我们在 JS 代码中使用的 Map 完全不是一个东西，它其实是包含描述指向它的 Heap Object 的结构信息的特殊 Heap Object，即经常被提到的 Hidden Class。::: IV. 元信息 (Meta Map) 既然所有的 JS 对象都继承自上一小节中提到的 Heap Object，那也意味着这些 JS 对象在 V8 引擎层面的存储对象必然会保存一个伪指针来指向用来描述这个 JS 对象结构的 Meta Map。 Layout 我们来看 V8 引擎对这样的 Meta Map 的结构描述: // Map layout: // +---------------+---------------------------------------------+ // | _ Type _ | _ Description _ | // +---------------+---------------------------------------------+ // | TaggedPointer | map - Always a pointer to the MetaMap root | // +---------------+---------------------------------------------+ // | Int | The first int field | // `---+----------+---------------------------------------------+ // | Byte | [instance_size] | // +----------+---------------------------------------------+ // | Byte | If Map for a primitive type: | // | | native context index for constructor fn | // | | If Map for an Object type: | // | | inobject properties start offset in words | // +----------+---------------------------------------------+ // | Byte | [used_or_unused_instance_size_in_words] | // | | For JSObject in fast mode this byte encodes | // | | the size of the object that includes only | // | | the used property fields or the slack size | // | | in properties backing store. | // +----------+---------------------------------------------+ // | Byte | [visitor_id] | // +----+----------+---------------------------------------------+ // | Int | The second int field | // `---+----------+---------------------------------------------+ // | Short | [instance_type] | // +----------+---------------------------------------------+ // | Byte | [bit_field] | // | | - has_non_instance_prototype (bit 0) | // | | - is_callable (bit 1) | // | | - has_named_interceptor (bit 2) | // | | - has_indexed_interceptor (bit 3) | // | | - is_undetectable (bit 4) | // | | - is_access_check_needed (bit 5) | // | | - is_constructor (bit 6) | // | | - has_prototype_slot (bit 7) | // +----------+---------------------------------------------+ // | Byte | [bit_field2] | // | | - new_target_is_base (bit 0) | // | | - is_immutable_proto (bit 1) | // | | - unused bit (bit 2) | // | | - elements_kind (bits 3..7) | // +----+----------+---------------------------------------------+ // | Int | [bit_field3] | // | | - enum_length (bit 0..9) | // | | - number_of_own_descriptors (bit 10..19) | // | | - is_prototype_map (bit 20) | // | | - is_dictionary_map (bit 21) | // | | - owns_descriptors (bit 22) | // | | - is_in_retained_map_list (bit 23) | // | | - is_deprecated (bit 24) | // | | - is_unstable (bit 25) | // | | - is_migration_target (bit 26) | // | | - is_extensible (bit 28) | // | | - may_have_interesting_symbols (bit 28) | // | | - construction_counter (bit 29..31) | // | | | // +*************************************************************+ // | Int | On systems with 64bit pointer types, there | // | | is an unused 32bits after bit_field3 | // +*************************************************************+ // | TaggedPointer | [prototype] | // +---------------+---------------------------------------------+ // | TaggedPointer | [constructor_or_backpointer] | // +---------------+---------------------------------------------+ // | TaggedPointer | [instance_descriptors] | // +*************************************************************+ // ! TaggedPointer ! [layout_descriptors] ! // ! ! Field is only present if compile-time flag ! // ! ! FLAG_unbox_double_fields is enabled ! // ! ! (basically on 64 bit architectures) ! // +*************************************************************+ // | TaggedPointer | [dependent_code] | // +---------------+---------------------------------------------+ // | TaggedPointer | [prototype_validity_cell] | // +---------------+---------------------------------------------+ // | TaggedPointer | If Map is a prototype map: | // | | [prototype_info] | // | | Else: | // | | [raw_transitions] | // +---------------+---------------------------------------------+ 这个 Meta Map 本身也是继承自 Heap Object，所以它的堆地址起始也是一个伪指针，显而易见的是这个 Tagged Pointer 不会再指向另一个用来描述自己的 Meta Map 了 (禁止套娃)。 Instance size 跟在这个 Tagged Pointer 后面的 4 个 byte (即上图中的第一个 Int) 的使用我们来看下其对应的作用: // +----------+---------------------------------------------+ // | Byte | [instance_size] | // +----------+---------------------------------------------+ // | Byte | If Map for a primitive type: | // | | native context index for constructor fn | // | | If Map for an Object type: | // | | inobject properties start offset in words | // +----------+---------------------------------------------+ // | Byte | [used_or_unused_instance_size_in_words] | // | | For JSObject in fast mode this byte encodes | // | | the size of the object that includes only | // | | the used property fields or the slack size | // | | in properties backing store. | // +----------+---------------------------------------------+ // | Byte | [visitor_id] | // +----------+---------------------------------------------+ 这里有一个比较重要的值是 instance_size，它记录了指向这个 Meta Map 的 Heap Object 的大小，换言之从 Meta Map 的首地址偏移 8 Byte 得到的新指针指向堆空间保存了原始 Heap Object 的实际占据 V8 堆空间的大小。这样说可能还是比较抽象，所以我们来看下 Heap Object Size 是如何被设置的，可以看到在 Map 类中定义了一个 set_instance_size_in_words 的成员方法: // src/objects/map-inl.h void Map::set_instance_size_in_words(int value) { RELAXED_WRITE_BYTE_FIELD(*this, kInstanceSizeInWordsOffset, static_cast<byte>(value)); } 将宏 RELAXED_WRITE_BYTE_FIELD 展开最终得到: // src/objects/map-inl.h void Map::set_instance_size_in_words(int value) { base::Relaxed_Store( reinterpret_cast<base::Atomic8*>( ((*this).ptr() + kInstanceSizeInWordsOffset - kHeapObjectTag)), static_cast<base::Atomic8>(static_cast<byte>(value))); } 其中 base::Relaxed_Store 的定义如下: // src/base/atomicops_internals_portable.h inline void Relaxed_Store(volatile Atomic8* ptr, Atomic8 value) { __atomic_store_n(ptr, value, __ATOMIC_RELAXED); } __atomic_store_n 是 gcc 定义的多线程下比信号量锁性能更好的原子存储操作操作，引用下 gcc 官方文档里的说法: This built-in function implements an atomic store operation. It writes val into *ptr. 其实就是把 value 写入 *ptr 指向的堆空间，__ATOMIC_RELAXED 表示不会对执行写入操作的线程设定优先级: __ATOMIC_RELAXED: Implies no inter-thread ordering constraints. 回到 set_instance_size_in_words 展开后的方法，它的作用描述下就是: 取 Meta Map 自己的伪指针（首地址加上 kInstanceSizeInWordsOffset 偏移量（这里是 8byte）转换成真实地址（伪指针最后一位伪 1）将 instance size 写入上面得到的真实地址指向的堆空间内值得注意的是，指针的加减运算和指针类型有关，所以上面代码中计算 instance 偏移量的时候首先将 Meta Map 的指针强转为 base::Atomic8 类型的指针，而 Atomic8 的实际上就是 char 的别名: // src/base/atomicops.h using Atomic8 = char; Instance type 因为每一个不同的 JS 对象类型布局除了头部的指向 Meta Map 的伪指针外都不一样，所以获取原始的 Heap Object 的类型就比较重要。这部分信息保存在第二个 Int (4 byte) 长度的区域里: // +----------+---------------------------------------------+ // | Short | [instance_type] | // +----------+---------------------------------------------+ // | Byte | [bit_field] | // | | - has_non_instance_prototype (bit 0) | // | | - is_callable (bit 1) | // | | - has_named_interceptor (bit 2) | // | | - has_indexed_interceptor (bit 3) | // | | - is_undetectable (bit 4) | // | | - is_access_check_needed (bit 5) | // | | - is_constructor (bit 6) | // | | - has_prototype_slot (bit 7) | // +----------+---------------------------------------------+ // | Byte | [bit_field2] | // | | - new_target_is_base (bit 0) | // | | - is_immutable_proto (bit 1) | // | | - unused bit (bit 2) | // | | - elements_kind (bits 3..7) | // +----------+---------------------------------------------+ 可以看到这里用了一个 short (2 byte) 的长度来保存原始 Heap Object 的类型信息，换言之从 Meta Map 的首地址偏移 12 Byte 得到新地址转换为 uint16_t 类型的地址后指向的堆空间得到的无符号整数即标识了原始 Heap Object 的类型。这里还是通过原始 Heap Object 的类型是如何被设置的来理解下这部分内容，Map 类中同样定义了一个 set_instance_type 的成员方法: void Map::set_instance_type(InstanceType value) { WriteField<uint16_t>(kInstanceTypeOffset, value); } InstanceType 是一个枚举类型，它定义了完整的 Heap Object 可能的类型: // src/objects/instance-type.h enum InstanceType : uint16_t { // .... }; 可以看到 InstanceType 继承自 uint16_t，正好是 2 byte，也和 Meta Map 中分配给实例类型一个 short 的长度来表示相吻合。接着我们看下 WriteField 函数究竟做了些什么: template <class T, typename std::enable_if<std::is_arithmetic<T>::value, int>::type = 0> inline void WriteField(size_t offset, T value) const { // Pointer compression causes types larger than kTaggedSize to be unaligned. #ifdef V8_COMPRESS_POINTERS constexpr bool v8_pointer_compression_unaligned = sizeof(T) > kTaggedSize; #else constexpr bool v8_pointer_compression_unaligned = false; #endif if (std::is_same<T, double>::value || v8_pointer_compression_unaligned) { // Bug(v8:8875) Double fields may be unaligned. base::WriteUnalignedValue<T>(field_address(offset), value); } else { base::Memory<T>(field_address(offset)) = value; } } 展开 field_address 得到: inline Address field_address(size_t offset) const { return ptr() + offset - kHeapObjectTag; } 它的作用就是通过指针偏移量来计算出真实的堆空间地址。最后看下 base::Memory 做了些什么: template <class T> inline T& Memory(Address addr) { DCHECK(IsAligned(addr, alignof(T))); return *reinterpret_cast<T*>(addr); } template <class T> inline T& Memory(byte* addr) { return Memory<T>(reinterpret_cast<Address>(addr)); } 有了以上的信息，我们进行下简单转换下可以得到可读性比较好的代码: inline void WriteField(size_t offset, uint16_t value) const { *reinterpret_cast<uint16_t *>(ptr() + offset - kHeapObjectTag) = value } 这样看就比较明确了，创建 Heap Object 的时候通过调用 set_instance_type 方法确实将一个类型为 uint16_t 的类型值存储到了 Meta Map 起始地址偏移 kInstanceTypeOffset 的堆空间内。 V. 还原 V8 对象了解了上述的这些内容，我们对于一个给定的地址 p，判断其为堆对象后可以: 根据 kMapOffset 来获取其指向的 Meta Map 根据 Meta Map 和 kInstanceSizeInWordsOffset 获取原始堆对象在 V8 堆上的大小根据 Meta Map 和 kInstanceTypeOffset 获取原始堆对象类型根据原始对象类型的布局来还原其各个属性值得一提的是，按照引擎的定义， Meta Map 的起始伪指针指向一个 Meta Map root (作为 GC root 方便 GC)，换言之所有的 JS 对象指向的 Meta Map 都指向了同一个 Meta Map root: // +---------------+---------------------------------------------+ // | TaggedPointer | map - Always a pointer to the MetaMap root | // +---------------+---------------------------------------------+ 这一点同样从导出的 HeapSnapshot 堆快照的分析中可以得到证实，这部分内容后面会在解析堆快照的文章中详细说明。 Meta Map 的定义里已经包含了逆工程 V8 对象的几乎绝大部分内容，下面一篇文章中我们会以一个例子来看下如何借助于 Meta Map 还原 JS Object 的原始信息。 VI. 参考资料解读 V8 GC Log（一）: Node.js 应用背景与 GC 基础知识 Bringing JavaScript Back to Life Built-in Functions for Memory Model Aware Atomic Operations LLNode - An lldb plugin for Node.js and V8

发表了文章 2019-04-22

Node.js 应用故障排查手册 —— 雪崩型内存泄漏问题

楔子实践篇一中我们也看到了一个比较典型的由于开发者不当使用第三方库，而且在配置信息中携带了三方库本身使用不到的信息，导致了内存泄漏的案例，实际上类似这种相对缓慢的 Node.js 应用内存泄漏问题我们总是可以在合适的机会抓取堆快照进行分析，而且堆快照一般来说确实是分析内存泄漏问题的最佳手段。但是还有一些问题场景下下应用的内存泄漏非常严重和迅速，甚至于在我们的告警系统感知之前就已经造成应用的 OOM 了，这时我们来不及或者说根本没办法获取到堆快照，因此就没有办法借助于之前的办法来分析为什么进程会内存泄漏到溢出进而 Crash 的原因了。这种问题场景实际上属于线上 Node.js 应用内存问题的一个极端状况，本节将同样从源自真实生产的一个案例来来给大家讲解下如何处理这类极端内存异常。本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。最小化复现代码同样我们因为例子的特殊性，我们需要首先给出到大家生产案例的最小化复现代码，建议读者自行运行一番此代码，这样结合起来看下面的排查分析过程会更有收获。最小复现代码还是基于 Egg.js，如下所示： 'use strict'; const Controller = require('egg').Controller; const fs = require('fs'); const path = require('path'); const util = require('util'); const readFile = util.promisify(fs.readFile); class DatabaseError extends Error { constructor(message, stack, sql) { super(); this.name = 'SequelizeDatabaseError'; this.message = message; this.stack = stack; this.sql = sql; } } class MemoryController extends Controller { async oom() { const { ctx } = this; let bigErrorMessage = await readFile(path.join(__dirname, 'resource/error.txt')); bigErrorMessage = bigErrorMessage.toString(); const error = new DatabaseError(bigErrorMessage, bigErrorMessage, bigErrorMessage); ctx.logger.error(error); ctx.body = { ok: false }; } } module.exports = MemoryController; 这里我们还需要在 app/controller/ 目录下创建一个 resource 文件夹，并且在这个文件夹中添加一个 error.txt，这个 TXT 内容随意，只要是一个能超过 100M 的很大的字符串即可。值得注意的是，其实这里的问题已经在 egg-logger >= 1.7.1 的版本中修复了，所以要复现当时的状况，你还需要在 Demo 的根目录执行以下的三条命令以恢复当时的版本状况： rm -rf package-lock.json rm -rf node_modules/egg/egg-logger npm install egg-logger@1.7.0 最后使用 npm run dev 启动这个问题最小化复现的 Demo。感知进程出现问题这个案例下，实际上我们的线上 Node.js 应用几乎是触发了这个 Bug 后瞬间内存溢出然后 Crash 的，而平台预设的内存阈值告警，实际上是由一个定时上报的逻辑构成，因此存在延时，也导致了这个案例下我们无法像冗余配置传递引发的内存溢出问题那样获取到 Node.js 进程级别的内存超过预设阈值的告警。那么我们如何来感知到这里的错误的呢？这里我们的服务器配置过了 ulimit -c unlimited ，因此 Node.js 应用 Crash 的时候内核会自动生成核心转储文件，而且性能平台目前也支持核心转储文件的生成预警，这一条规则目前也被放入了预设的快速添加告警规则中，可以参考工具篇中 Node.js 性能平台使用指南 - 配置合适的告警一节，详细的规则内容如下所示：这里需要注意的是，核心转储文件告警需要我们在服务器上安装的 Agenthub/Agentx 依赖的 Commandx 模块的版本在 1.5.2 之上（包含），这一块更详细的信息也可以看官方文档核心转储分析能力一节。问题排查过程 I. 分析栈信息依靠上面提到的平台提供的核心转储文件生成时给出的告警，我们在收到报警短信时登录控制台，可以看到 Coredump 文件列表出现了新生成的核心转储文件，继续参照工具篇中 Node.js 性能平台使用指南 - 核心转储分析中给出的转储和 AliNode 定制分析的过程，我们可以看到如下的分析结果展示信息：同样我们直接展开 JavaScript 栈信息查看应用 Crash 那一刻的栈信息：截图中忽略掉了 Native C/C++ 代码的栈信息，这里其实仅仅看 JavaScript 栈信息就能得到结论了，通过翻阅比对出问题的 egg-logger@1.7.0 中 lib/utils.js 的代码内容： function formatError(err) { // ... // 这里对 Error 对象的 key 和 value 调用 inspect 方法进行序列化 const errProperties = Object.keys(err).map(key => inspect(key, err[key])).join('\n'); // ... } // inspect 方法实际上是调用 require('util').inspect 来对错误对象的 value 进行序列化 function inspect(key, value) { return `${key}: ${util.inspect(value, { breakLength: Infinity })}`; } 这样我们就知道了线上 Node.js 应用在 Crash 的那一刻正在使用 require('util').inspect 对某个字符串进行序列化操作。 II. 可疑字符串那么这个序列化的动作究竟是不是造成进程 Crash 的元凶呢？我们接着来点击 inspect 函数的参数来展开查看这个可疑的字符串的详细信息，如下图所示：点击红框中的参数，得到字符串的详情页面链接，如下图所示：再次点击这里的 detail 链接，既可在弹出的新页面中看到这个可疑字符串的全部信息：这里可以看到，这个正在被 util.inspect 的字符串大小高达 186.94 兆，显然正是在序列化这么大的字符串的时候，造成了线上 Node.js 应用的堆内存雪崩，几乎在瞬间就内存溢出导致 Crash。值得一提的是，我们还可以点击上图中的 + 号来在当前页面展示更多的问题字符串内容：也可以在页面上点击一键导出按钮下载问题完整的字符串：毕竟对于这样的问题来说，如果能抓到产生问题的元凶参数，起码能更方便地进行本地复现。 III. 修复问题那么知道了原因，其实修复此问题就比较简单了，Egg-logger 官方是使用 circular-json 来替换掉原生的 util.inspect 序列化动作，并且增加序列化后的字符串最大只保留 10000 个字符的限制，这样就解决这种包含大字符串的错误对象在 Egg-logger 模块中的序列化问题。结尾本节的给大家展现了对于线上 Node.js 应用出现瞬间 Crash 问题时的排查思路，而在最小化复现 Demo 对应的那个真实线上故障中，实际上是拼接的 SQL 语句非常大，大小约为 120M，因此首先导致数据库操作失败，接着数据库操作失败后输出的 DatabaseError 对象实例上则原封不动地将问题 SQL 语句设置到属性上，从而导致了 ctx.logger.error(error) 时堆内存的雪崩。在 Node.js 性能平台提供的核心转储告警 + 在线分析能力的帮助下，此类无法获取到常规 CPU Profile 和堆快照等信息的进程无故崩溃问题也变得有迹可循了，实际上它作为一种兜底分析手段，在很大程度上提升了开发者真正将 Node.js 运用到服务端生产环境中的信心。

发表了文章 2019-04-13

Node.js 应用故障排查手册 —— 类死循环导致进程阻塞

楔子在实践篇一中我们看到了两个表象都是和 CPU 相关的生产问题，它们基本也是我们在线上可能遇到的这一类问题的典型案例，而实际上这两个案例也存在一个共同点：我们可以通过 Node.js 性能平台导出进程对应的 CPU Profile 信息来进行分析定位问题，但是实际在线上的一些极端情况下，我们遇到的故障是没有办法通过轻量的 V8 引擎暴露的 CPU Profile 接口（仅部分定制的 AliNode runtime 版本支持，详见下文）来获取足够的进程状态信息进行分析的，此时我们又回到了束手无策的状态。本章节将从一个生产环境下 Node.js 应用出现进程级别阻塞导致的不再提供服务的问题场景来给大家展示下如何处理这类相对极端的应用故障。本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。最小化复现代码这个例子稍微有些特殊，我们首先给出生产案例的最小化复现代码，有兴趣的同学可以亲自运行一番，这样结合下文的此类问题的排查过程，能更加清晰的看到我们面对这样的问题时的排查思路，问题最小代码如下，基于 Egg.js ： 'use strict'; const Controller = require('egg').Controller; class RegexpController extends Controller { async long() { const { ctx } = this; // str 模拟用户输入的问题字符串 let str = ' ' + ' 早餐后自由活动，于指定时间集合自行办理退房手续。'; str += ' ' + ' ' + ' '; str += ' ' + ' ' + ' ' + ' '; str += ' '; str += ' ' + ' ' + ' 根据船班时间，自行前往暹粒机场，返回中国。 '; str += '如需送机服务，需增加280/每单。 '; const r = str.replace(/(^(\s*?<br[\s\/]*?>\*?)+|(\s*?<br[\s\/]*?>\s*?)+?$)/igm, ''); ctx.body = r; } } module.exports = RegexpController; 问题应用状态其实这个例子对应的问题场景可能很多 Node.js 开发者都遇到过，它非常有意思，我们首先来看下出现这类故障时我们的 Node.js 应用的状态。当我们收到在平台配置的 CPU 告警信息后，登录性能平台进入对应的告警应用找到出问题的 CPU 非常高的进程：然后点击数据趋势按钮查看此进程当前的状态信息：可以看到进程的 CPU 使用率曲线一直处于近乎 100% 的状态，此时进程不再响应其余的请求，而且我们通过跳板机进入生产环境又可以看到进程其实是存活的，并没有挂掉，此时基本上可以判断：此 Node.js 进程因为在执行某个同步函数处于阻塞状态，且一直卡在此同步函数的执行上。 Node.js 的设计运行模式就是单主线程，并发靠的是底层实现的一整套异步 I/O 和事件循环的调度。简单的说，具体到事件循环中的某一次，如果我们在执行需要很长时间的同步函数（比如需要循环执行很久才能跳出的 while 循环），那么整个事件循环都会阻塞在这里等待其结束后才能进入下一次，这就是不推荐大家在非初始化的逻辑中使用诸如 fs.readFileSync 等同步方法的原因。排查方法这样的问题其实非常难以排查，原因在于我们没办法知道什么样的用户输入造成了这样的阻塞，所以本地几乎无法复现问题。幸运的是，性能平台目前有不止一种解决办法处理这种类死循环的问题，我们来详细看下。 I. CPU Profile 这个分析方法可以说是我们的老朋友了，因为类死循环的问题本质上也是 CPU 高的问题，因此我们只要对问题进程抓取 CPU Profile，就能看到当前卡在哪个函数了。需要注意的是，进程假死状态下是无法直接使用 V8 引擎提供的抓取 CPU Profile 文件的接口，因此工具篇章节的正确打开 Chrome devtools 一节中提到的 v8-profiler 这样的第三方模块是无法正常工作的。不过定制过的 AliNode runtime 采用了一定的方法规避了这个问题，然而遗憾的是依旧并不是所有的 AliNode runtime 版本都支持在类死循环状态下抓取 CPU Profile，这里实际上对大家使用的 Runtime 版本有要求： AliNode V3 版本需要 >= v3.11.4 AliNode V4 版本需要 >= v4.2.1 AliNode V1 和 V2 版本不支持如果你的线上 AliNode runtime 版本恰好符合需求，那么可以按照前面 Node.js 性能平台使用指南提到的那样，对问题进程抓取 3 分钟的 CPU Profile，并且使用 AliNode 定制的火焰图分析：这里可以看到，抓取到的问题进程 3 分钟的 CPU 全部耗费在 long 函数里面的 replace 方法上，这和我们提供的最小化复现代码一致，因此可以判断 long 函数内的正则存在问题进行修复。 II. 诊断报告诊断报告也是 AliNode 定制的一项导出更多更详细的 Node.js 进程当前状态的能力，导出的信息也包含当前的 JavaScript 代码执行栈以及一些其它进程与系统信息。它与 CPU Profile 的区别主要在两个地方：诊断报告主要针对此刻进程状态的导出，CPU Profile 则是一段时间内的 JavaScript 代码执行状态诊断报告除了此刻 JavaScript 调用栈信息，还包含了 Native C/C++ 栈信息、Libuv 句柄和部分操作系统信息当我们的进程处于假死状态时，显然不管是一段时间内还是此时此刻的 JavaScript 执行状况，必然都是卡在我们代码中的某个函数上，因此我们可以使用诊断报告来处理这样的问题，当然诊断报告功能同样也对 AliNode runtime 版本有所要求： AliNode V2 版本需要 >= v2.5.2 AliNode V3 版本需要 >= v3.11.8 AliNode V4 版本需要 >= v4.3.0 AliNode V1 版本不支持且要求：Agenthub/Egg-alinode 依赖的 Commandx 版本 >= v1.5.3 如果你使用的 AliNode runtime 版本符合要求，即可进入平台应用对应的实例信息页面，选中问题进程：然后点击诊断报告即可生成此刻问题进程的状态信息报告：诊断报告虽然包含了很多的进程和系统信息，但是其本身是一个相对轻量的操作，故而很快就会结束，此时继续点击转储按钮将生成的诊断报告上传至云端以供在线分析展示：继续点击分析按钮查看 AliNode 定制的分析功能，展示结果如下：结果页面上面的概览信息比较简单，我们来看下 JavaScript 栈页面的内容，这里显然也告诉我们当前的 JS 函数卡在 long 方法里面，并且比 CPU Profile 更加详细的是还带上了具体阻塞在 long 方法的哪一行，对比我们提供给大家的最小复现代码其实就是执行 str.replace 这一行，也就是问题的正则匹配操作所在的地方。 III. 核心转储分析其实很多朋友看到这里会有疑惑：既然 CPU Profile 分析和诊断报告已经能够找到问题所在了，为什么我们还要继续介绍相对比较重的核心转储分析功能呢？其实道理也很简单，不管是类死循环状态下的 CPU Profile 抓取还是诊断报告功能的使用，都对问题进程的 AliNode runtime 版本有所要求，而且更重要的是，这两种方法我们都只能获取到问题正则的代码位置，但是我们无法知道什么样的用户输入在执行这样的正则时会触发进程阻塞的问题，这会给我们分析和给出针对性的处理造成困扰。因此，这里最后给大家介绍对 AliNode runtime 版本没有任何要求，且能拿到更精准信息的核心转储分析功能。首先按照预备章节的核心转储一节中提到的手动生成 Core dump 文件的方法，我们对问题进程进行 sudo gcore <pid> 的方式获取到核心转储文件，然后在平台的详情页面，将鼠标移动到左边 Tab 栏目的文件按钮上，可以看到 Coredump 文件的按钮：点击后可以进入 Core dump 文件列表页，然后点击上方的上传按钮进行核心转储文件的上传操作：这里需要注意的是，请将 Core dump 文件以 .core 结尾重命名，而对应的 Node 可执行文件以 .node 结尾重命名，推荐的命名方式为 <os info>-<alinode/node>-<version>.node，方便以后回顾，比如 centos7-alinode-v4.7.2.node 这种。最后 Core dump 文件和 Node 可执行文件之间必须是一一对应的关系。这里一一对应指的是：这份 Core dump 文件必须是由这个 Node 可执行文件启动的进程生成的，如果这两者没有一一对应，分析结果往往是无效信息。因为 Core dump 文件一般来说都比较大，所以上传会比较慢，耐心等待至上传完毕后，我们就可以使用 AliNode 定制的核心转储文件分析功能进行分析了，点击分析按钮即可：此时我们在新打开的分析结果页面可以看到如下的分析结果展示信息：这个页面的各项含义在工具篇的 Node.js 性能平台使用指南的 [最佳实践——核心转储分析]() 一节已经解释过，这里不再赘述，这里直接展开 JavaScript 栈信息：这里可以看到得到的结论和前面的 CPU Profile 分析以及诊断报告分析一致，都能定位到提供的最小复现代码中的 long 方法中的异常正则匹配，但是核心转储文件分析比前面两者多了导致当前 Node.js 进程产生问题的异常字符串： " 早餐后自由活动，于指定时间集合自行办理退房手续。 根据船班时间，自行前往暹粒机场，返回中国。 如需送机服务，需增加280/每单。 " ，有了这个触发正则执行异常的问题字符串，我们无论是构造本地复现样例还是进一步分析都有了重要的信息依靠。分析问题上一节中我们采用了 Node.js 性能平台提供的三种不同的方式分析定位到了线上应用处于假死状态的原因，这里来简单的解释下为什么字符串的正则匹配会造成类死循环的状态，它实际上异常的用户输入触发了正则表达式灾难性的回溯，会导致执行时间要耗费几年甚至几十年，显然不管是那种情况，单主工作线程的模型会导致我们的 Node.js 应用处于假死状态，即进程依旧存活，但是却不再处理新的请求。关于正则回溯的原因有兴趣的同学可以参见小心别落入正则回溯陷阱一文。结尾其实这类正则回溯引发的进程级别阻塞问题，本质上都是由于不可控的用户输入引发的，而 Node.js 应用又往往作为 Web 应用直接面向一线客户，无时不刻地处理千奇百怪的用户请求，因此更容易触发这样的问题。相似的问题其实还有一些代码逻辑中诸如 while 循环的跳出条件在一些情况下失效，导致 Node.js 应用阻塞在循环中。之前我们就算知道是进程阻塞也难以方便的定位到具体的问题代码以及产生问题的输入，现在借助于 Node.js 性能平台提供的核心转储分析能力，相信大家可以比较容易地来解决这样的问题。

发表了文章 2019-04-08

Node.js 应用故障排查手册 —— 综合性 GC 问题和优化

楔子本章前面两节生产案例分别侧重于单一的 CPU 高和单一的内存问题，我们也给大家详细展示了问题的定位排查过程，那么实际上还有一类相对更复杂的场景——它本质上是 V8 引擎的 GC 引发的问题。简单的给大家介绍下什么是 GC，GC 实际上是语言引擎实现的一种自动垃圾回收机制，它会在设定的条件触发时（比如堆内存达到一定值）时查看当前堆上哪些对象已经不再使用，并且将这些没有再使用到的对象所占据的空间释放出来。许多的现代高级语言都实现了这一机制，来减轻程序员的心智负担。本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。 GC 带来的问题虽然上面介绍中现代语言的 GC 机制解放了程序员间接提升了开发效率，但是万事万物都存在利弊，底层的引擎引入 GC 后程序员无需再关注对象何时释放的问题，那么相对来说程序员也就没办法实现对自己编写的程序的精准控制，它带来两大问题：代码编写问题引发的内存泄漏程序执行的性能降低内存泄漏问题我们已经在上一节的生产案例中体验了一下，那么后者是怎么回事呢？其实理解起来也很简单：原本一个程序全部的工作都是执行业务逻辑，但是存在了 GC 机制后，程序总会在一定的条件下耗费时间在扫描堆空间找出不再使用的对象上，这样就变相降低了程序执行业务逻辑的时间，从而造成了性能的下降，而且降低的性能和耗费在 GC 上的时间，换言之即 GC 的次数 * 每次 GC 耗费的时间成正比。问题现象与原始分析现在大家应该对 GC 有了一个比较整体的了解，这里我们可以看下 GC 引发的问题在生产中的表现是什么样的。在这个案例中，表象首先是 Node.js 性能平台上监控到进程的 CPU 达到 100%，但是此时服务器负载其实并不大，QPS 只有 100 上下，我们按照前面提到的处理 CPU 问题的步骤抓取 CPU Profile 进行分析可以看到：这次的问题显然是 Garbage Collector 耗费的 CPU 太多了，也就是 GC 的问题。实际上绝大部分的 GC 机制引发的问题往往表象都是反映在 Node.js 进程的 CPU 上，而本质上这类问题可以认为是引擎的 GC 引起的问题，也可以理解为内存问题，我们看下这类问题的产生流程：堆内存不断达到触发 GC 动作的预设条件进程不断触发 GC 操作进程 CPU 飙高而且 GC 问题不像之前的 ejs 模板渲染引发的问题，就算我们在 CPU Profile 中可以看到这部分的耗费，但是想要优化解决这个问题基本是无从下手的，幸运的是 Node.js 提供了（其实是 V8 引擎提供的）一系列的启动 Flag 能够输出进程触发 GC 动作时的相关日志以供开发者进行分析： --trace_gc: 一行日志简要描述每次 GC 时的时间、类型、堆大小变化和产生原因 --trace_gc_verbose: 结合 --trace_gc 一起开启的话会展示每次 GC 后每个 V8 堆空间的详细状况 --trace_gc_nvp: 每一次 GC 的一些详细键值对信息，包含 GC 类型，暂停时间，内存变化等信息加粗的 Flag 意味着我们需要在启动应用前加上才能在运行时生效，这部分的日志实际上是一个文本格式，可惜的是 Chrome devtools 原生并不支持 GC 日志的解析和结果展示，因此需要大家获取到以后进行对应的按行解析处理，当然我们也可以使用社区提供 v8-gc-log-parser 这个模块直接进行解析处理，对这一块有兴趣的同学可以看 @joyeeCheung 在 JS Interactive 的分享: Are Your V8 Garbage Collection Logs Speaking To You?，这里不详细展开。更好的 GC 日志展示虽然 Chrome devtools 并不能直接帮助我们解析展示 GC 日志的结果，但是 Node.js 性能平台其实给大家提供了更方便的动态获取线上运行进程的 GC 状态信息以及对应的结果展示，换言之，开发者无需在运行你的 Node.js 应用前开启上面提到的那些 Flag 而仍然可以在想要获取到 GC 信息时通过控制台拿到 3 分钟内的 GC 数据。对应在这个案例中，我们可以进入平台的应用实例详情页面，找到 GC 耗费特别大的进程，然后点击 GC Trace 抓取 GC 数据：这里默认会抓取 3 分钟的对应进程的 GC 日志信息，等到结束后生成的文件会显示在文件页面：此时点击转储即可上传到云端以供在线分析展示了，如下图所示：最后点击这里的分析按钮，即可看到 AliNode 定制后的 GC 信息分析结果的展现：结果展示中，可以比较方便的看到问题进程的 GC 具体次数，GC 类型以及每次 GC 的耗费时间等信息，方便我们进一步的分析定位。比如这次问题的 GC Trace 结果分析图中，我们可以看到红圈起来的几个重要信息： GC 总暂停时间高达 47.8s，大头是 Scavenge 3min 的 GC 追踪日志里面，总共进行了 988 次的 Scavenge 回收每次 Scavenge 耗时均值在 50 ~ 60ms 之间从这些解困中我们可以看到此次 GC 案例的问题点集中在 Scavenge 回收阶段，即新生代的内存回收。那么通过翻阅 V8 的 Scavenge 回收逻辑可以知道，这个阶段触发回收的条件是：Semi space allocation failed。这样就可以推测，我们的应用在压测期间应该是在新生代频繁生成了大量的小对象，导致默认的 Semi space 总是处于很快被填满从而触发 Flip 的状态，这才会出现在 GC 追踪期间这么多的 Scavenge 回收和对应的 CPU 耗费，这样这个问题就变为如何去优化新生代的 GC 来提升应用性能。优化新生代 GC 通过平台提供的 GC 数据抓取和结果分析，我们知道可以去尝试优化新生代的 GC 来达到提升应用性能的目的，而新生代的空间触发 GC 的条件又是其空间被占满，那么新生代的空间大小由 Flag --max-semi-space-size 控制，默认为 16MB，因此我们自然可以想到要可以通过调整默认的 Semi space 的值来进行优化。这里需要注意的是，控制新生代空间的 Flag 在不同的 Node.js 版本下并不是一样的，大家具体可以查看当前的版本来进行确认使用。在这个案例中，显然是默认的 16M 相对当前的应用来说显得比较小，导致 Scavenge 过于频繁，我们首先尝试通过启动时增加 --max-semi-space-size=64 这个 Flag 来将默认的新生代使用到的空间大小从 16M 的值增大为 64M，并且在流量比较大而且进程 CPU 很高时抓取 CPU Profile 观察效果：调整后可以看到 Garbage collector 阶段 CPU 耗费占比下降到 7% 左右，再抓取 GC Trace 并观察其展示结果确认是不是 Scavenge 阶段的耗费下降了：显然，Semi space 调大为 64M 后，Scavenge 次数从近 1000 次降低到 294 次，但是这种状况下每次的 Scavenge 回收耗时没有明显增加，还是在 50 ~ 60ms 之间波动，因此 3 分钟的 GC 追踪总的停顿时间从 48s 下降到 12s，相对应的，业务的 QPS 提升了约 10% 左右。那么如果我们通过 --max-semi-space-size 这个 Flag 来继续调大新生代使用到的空间，是不是可以进一步优化这个应用的性能呢？此时尝试 --max-semi-space-size=128 来从 64M 调大到 128M，在进程 CPU 很高时继续抓取 CPU Profile 来查看效果：此时 Garbage collector 耗费下降相比上面的设置为 64M 并不是很明显，GC 耗费下降占比不到 1%，同样我们来抓取并观察下 GC Trace 的结果来查看具体的原因：很明显，造成相比设置为 64M 时 GC 占比提升不大的原因是：虽然此时进一步调大了 Semi space 至 128M，并且 Scavenge 回收的次数确实从 294 次下降到 145 次，但是每次算法回收耗时近乎翻倍了，因此总收益并不明显。按照这个思路，我们再使用 --max-semi-space-size=256 来将新生代使用的空间进一步增大到 256M 再来进行最后一次的观察：这里和调整为 128M 时是类似的情况： 3 分钟内 Scavenge 次数从 294 次下降到 72 次，但是相对的每次算法回收耗时波动到了 150ms 左右，因此整体性能并没有显著提升。借助于性能平台的 GC 数据抓取和结果展示，通过以上的几次尝试改进 Semi space 的值后，我们可以看到从默认的 16M 设置到 64M 时，Node 应用的整体 GC 性能是有显著提升的，并且反映到压测 QPS 上大约提升了 10%；但是进一步将 Semi space 增大到 128M 和 256M 时，收益确并不明显，而且 Semi space 本身也是作用于新生代对象快速内存分配，本身不宜设置的过大，因此这次优化最终选取对此项目最优的运行时 Semi space 的值为 64M。结尾在本生产案例中，我们首先可以看到，项目使用的三方库其实也并不总是在所有场景下都不会有 Bug 的（实际上这是不可能的），因此在遇到三方库的问题时我们要敢于去从源码的层面来对问题进行深入的分析。最后实际上在生产环境下通过 GC 方面的运行时调优来提升我们的项目性能是一种大家不那么常用的方式，这也有很大一部分原因是应用运行时 GC 状态本身不直接暴露给开发者。通过上面这个客户案例，我们可以看到借助于 Node.js 性能平台，实时感知 Node 应用 GC 状态以及进行对应的优化，使得不改一行代码提升项目性能变成了一件非常容易的事情。

发表了文章 2019-03-30

Node.js 应用故障排查手册 —— 冗余配置传递引发的内存溢出

楔子前面一小节我们以一个真实的压测案例来给大家讲解如何利用 Node.js 性能平台生成的 CPU Profile 分析来进行压测时的性能调优。那么与 CPU 相关的问题相比，Node.js 应用中由于不当使用产生的内存问题是一个重灾区，而且这些问题往往都是出现在生产环境下，本地压测都难以复现，实际上这部分内存问题也成为了很多的 Node.js 开发者不敢去将 Node.js 这门技术栈深入运用到后端的一大阻碍。本节将以一个开发者容易忽略的生产内存溢出案例，来展示如何借助于性能平台实现对线上应用 Node.js 应用出现内存泄漏时的发现、分析、定位问题代码以及修复的过程，希望能对大家有所启发。本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。最小化复现代码因为内存问题相对 CPU 高的问题来说比较特殊，我们直接从问题排查的描述可能不如结合问题代码来看比较直观，因此在这里我们首先给出了最小化的复现代码，大家运行后结合下面的分析过程应该能更有收获，样例基于 Egg.js：如下所示： 'use strict'; const Controller = require('egg').Controller; const DEFAULT_OPTIONS = { logger: console }; class SomeClient { constructor(options) { this.options = options; } async fetchSomething() { return this.options.key; } } const clients = {}; function getClient(options) { if (!clients[options.key]) { clients[options.key] = new SomeClient(Object.assign({}, DEFAULT_OPTIONS, options)); } return clients[options.key]; } class MemoryController extends Controller { async index() { const { ctx } = this; const options = { ctx, key: Math.random().toString(16).slice(2) }; const data = await getClient(options).fetchSomething(); ctx.body = data; } } module.exports = MemoryController; 然后在 app/router.js 中增加一个 Post 请求路由： router.post('/memory', controller.memory.index); 造成问题的 Post 请求 Demo 这里也给出来，如下所示： 'use strict'; const fs = require('fs'); const http = require('http'); const postData = JSON.stringify({ // 这里的 body.txt 可以放一个比较大 2M 左右的字符串 data: fs.readFileSync('./body.txt').toString() }); function post() { const req = http.request({ method: 'POST', host: 'localhost', port: '7001', path: '/memory', headers: { 'Content-Type': 'application/json', 'Content-Length': Buffer.byteLength(postData) } }); req.write(postData); req.end(); req.on('error', function (err) { console.log(12333, err); }); } setInterval(post, 1000); 最后我们在启动完成最小化复现的 Demo 服务器后，再运行这个 Post 请求的客户端，1s 发起一个 Post 请求，在平台控制台可以看到堆内存在一直增加，如果我们按照本书工具篇中的 Node.js 性能平台使用指南 - 配置合适的告警一节中配置了 Node.js 进程堆内存告警的话，过一会就会收到平台的短信/邮件提醒。问题排查过程收到性能平台的进程内存告警后，我们登录到控制台并且进入应用首页，找到告警对应实例上的问题进程，然后参照工具篇中的 Node.js 性能平台使用指南 - 内存泄漏中的方法抓取堆快照，并且点击分析按钮查看 AliNode 定制后的分解结果展示：这里默认的报表页面顶部的信息含义已经提到过了，这里不再重复，我们重点来看下这里的可疑点信息：提示有 18 个对象占据了 96.38% 的堆空间，显然这里就是我们需要进一步查看的点。我们可以点击对象名称来看到这18 个 system/Context 对象的详细内容：这里进入的是分别以这 18 个 system/Context 为根节点起始的支配树视图，因此展开后可以看到各个对象的实际内存占用情况，上图中显然问题集中在第一个对象上，我们继续展开查看：很显然，这里真正吃掉堆空间的是 451 个 SomeClient 实例，面对这样的问题我们需要从两个方面来判断这是否真的是内存异常的问题：当前的 Node.js 应用在正常的逻辑下，是否单个进程需要 451 个 SomeClient 实例如果确实需要这么多 SomeClient 实例，那么每个实例占据 1.98MB 的空间是否合理对于第一个判断，在对应的实际生产面临的问题中，经过代码逻辑的重新确认，我们的应用确实需要这么多的 Client 实例，显然此时排查重点集中在每个实例的 1.98MB 的空间占用是否合理上，假如进一步判断还是合理的，这意味着 Node.js 默认单进程 1.4G 的堆上限在这个场景下是不适用的，需要我们来通过启动 Flag 调大堆上限。正是基于以上的判断需求，我们继续点开这些 SomeClient 实例进行查看：这里可以很清晰的看到，这个 SomeClient 本身只有 1.97MB 的大小，但是下面的 options 属性对应的 Object@428973 对象一个就占掉了 1.98M，进一步展开这个可疑的 Object@428973 对象可以看到，其 ctx 属性对应的 Object@428919 对象正是 SomeClient 实例占据掉如此大的对空间的根本原因所在！我们可以点击其它的 SomeClient 实例，可以看到每一个实例均是如此，此时我们需要结合代码，判断这里的 options.ctx 属性挂载到 SomeClient 实例上是否也是合理的，点击此问题 Object 的地址：进入到这个 Object 的关系图中： Search 展示的视图不同于 Dom 结果图，它实际上展示的是从堆快中解析出来的原始对象关系图，所以边信息是一定会存在的，靠边名称和对象名称，我们比较容易判断对象在代码中的位置。但是在这个例子中，仅仅依靠以 Object@428973 为起始点的内存原始关系图，看不到很明确的代码位置，毕竟不管是 Object.ctx 还是 Object.key 都是相当常见的 JavaScript 代码关系，因此我们继续点击 Retainer 视图：得到如下信息：这里的 Retainer 信息和 Chrome Devtools 中的 Retainer 含义是一样的，它代表了节点在堆内存中的原始父引用关系，正如本文的内存问题案例中，仅靠可疑点本身以及其展开无法可靠地定位到问题代码的情况下，那么展开此对象的 Retainer 视图，可以看到它的父节点链路可以比较方便的定位到问题代码。这里我们显然可以通过在 Retainer 视图下的问题对象父引用链路，很方便地找到代码中创建此对象的代码： function getClient(options) { if (!clients[options.key]) { clients[options.key] = new SomeClient(Object.assign({}, DEFAULT_OPTIONS, options)); } return clients[options.key]; } 结合看 SomeClient 的使用，看到用于初始化的 options 参数中实际上只是用到了其 key 属性，其余的属于冗余的配置信息，无需传入。代码修复与确认知道了原因后修改起来就比较简单了，单独生成一个 SomeClient 使用的 options 参数，并且仅将需要的数据从传入的 options 参数上取过来以保证没有冗余信息即可： function getClient(options) { const someClientOptions = Object.assign({ key: options.key }, DEFAULT_OPTIONS); if (!clients[options.key]) { clients[options.key] = new SomeClient(someClientOptions); } return clients[options.key]; } 重新发布后运行，可以到堆内存下降至只有几十兆，至此 Node.js 应用的内存异常的问题完美解决。结尾本节中也比较全面地给大家展示了如何使用 Node.js 性能平台来排查定位线上应用内存泄漏问题，其实严格来说本次问题并不是真正意义上的内存泄漏，像这种配置传递时开发者图省事直接全量 Assign 的场景我们在写代码时或多或少时都会遇到，这个问题带给我们的启示还是：当我们去编写一个公共组件模块时，永远不要去相信使用者的传入参数，任何时候都应当只保留我们需要使用到的参数继续往下传递，这样可以避免掉很多问题。

发表了文章 2019-03-25

Node.js 应用故障排查手册 —— 利用 CPU 分析调优吞吐量

楔子在我们想要新上线一个 Node.js 应用之前，尤其是技术栈切换的第一个 Node.js 应用，由于担心其在线上的吞吐量表现，肯定会想要进行性能压测，以便对其在当前的集群规模下能抗住多少流量有一个预估。本案例实际上正是在这样的一个场景下，我们想要上线 Node.js 技术栈来做前后端分离，那么刨开后端服务的响应 QPS，纯使用 Node.js 进行的模板渲染能有怎么样的表现，这是大家非常关心的问题。本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。优化过程集群在性能压测下反映出来的整体能力其实由单机吞吐量就可以测算得知，因此这次的性能压测采用的 4 核 8G 内存的服务器进行压测，并且页面使用比较流行的 ejs 进行服务端渲染，进程数则按照核数使用 PM2 启动了四个业务子进程来运行。 I. 开始压测完成这些准备后，使用阿里云提供的 PTS 性能压测工具进行压力测试，此时大致单机 ejs 模板渲染的 QPS 在 200 左右，此时通过 Node.js 性能平台监控可以看到四个子进程的 CPU 基本都在 100%，即 CPU 负载达到了瓶颈，但是区区 200 左右的 QPS 显然系统整体渲染非常的不理想。 II. 模板缓存因为是 CPU 达到了系统瓶颈导致整体 QPS 上不去，因此按照第二部分工具篇章节的方法，我们在平台上抓了压测期间的 3 分钟的 CPU Profile，展现的结果如下图所示：这里就看到了很奇怪的地方，因为压测环境下我们已经打开了模板缓存，按理来说不会再出现 ejs.compile 函数对应的模板编译才对。仔细比对项目中的渲染逻辑代码，发现这部分采用了一个比较不常见的模块 koa-view，项目开发者想当然地用 ejs 模块地入参方式传入了 cache: true，但是实际上该模块并没有对 ejs 模板做更好的支持，因此实际压测情况下模板缓存并没有生效，而模板地编译动作本质上字符串处理，它恰恰是一个 CPU 密集地操作，这就导致了 QPS 达不到预期的状况。了解到原因之后，首先我们将 koa-view 替换为更好用的 koa-ejs 模块，并且按照 koa-ejs 的文档正确开启缓存： render(app, { root: path.join(__dirname, 'view'), viewExt: 'html', cache: true }); 再次进行压测后，单机下的 QPS 提升到了 600 左右，虽然大约提升了三倍的性能，但是仍然达不到预期的目标。 III. include 编译为了继续优化进一步提升服务器的渲染性能，我们继续在压测期间抓取 3 分钟的 CPU Profile 进行查看：可以看到，我们虽然已经确认使用 koa-ejs 模块且正确开启了缓存，但是压测期间的 CPU Profile 里面竟然还有 ejs 的 compile 动作！继续展开这里的 compile，发现是 includeFile 时引入的，继续回到项目本身，观察压测的页面模板，确实使用了 ejs 注入的 include 方法来引入其它模板： <%- include("../xxx") %> 对比 ejs 的源代码后，这个注入的 include 函数调用链确实也是 include -> includeFile -> handleCache -> compile，与压测得到的 CPU Profile 展示的内容一致。那么下面红框内的 replace 部分也是在 compile 过程中产生的。到了这里开始怀疑 koa-ejs 模块没有正确地将 cache 参数传递给真正负责渲染地 ejs 模块，导致这个问题地发生，所以继续去阅读 koa-ejs 的缓存设置，以下是简化后的逻辑（koa-ejs@4.1.1 版本）： const cache = Object.create(null); async function render(view, options) { view += settings.viewExt; const viewPath = path.join(settings.root, view); // 如果有缓存直接使用缓存后的模板解析得到的函数进行渲染 if (settings.cache && cache[viewPath]) { return cache[viewPath].call(options.scope, options); } // 没有缓存首次渲染调用 ejs.compile 进行编译 const tpl = await fs.readFile(viewPath, 'utf8'); const fn = ejs.compile(tpl, { filename: viewPath, _with: settings._with, compileDebug: settings.debug && settings.compileDebug, debug: settings.debug, delimiter: settings.delimiter }); // 将 ejs.compile 得到的模板解析函数缓存起来 if (settings.cache) { cache[viewPath] = fn; } return fn.call(options.scope, options); } 显然，koa-ejs 模板的模板缓存是完全自己实现的，并没有在调用 ejs.compile 方法时传入的 option 参数内将用户设置的 cache 参数传递过去而使用 ejs 模块提供的 cache 能力。但是偏偏项目在模板内又直接使用了 ejs 模块注入的 include 方法进行模板间的调用，产生的结果就是只缓存了主模板，而主模板使用 include 调用别的模板还是会重新进行编译解析，进而造成压测下还是存在大量重复的模板编译动作导致 QPS 升不上去。再次找到了问题的根源，为了验证是否是 koa-ejs 模块本身的 bug，我们在项目中将其渲染逻辑稍作更改： const fn = ejs.compile(tpl, { filename: viewPath, _with: settings._with, compileDebug: settings.debug && settings.compileDebug, debug: settings.debug, delimiter: settings.delimiter, // 将用户设置的 cache 参数传递给 ejs 而使用到其提供的缓存能力 cache: settings.cache }); 然后打包后进行压测，此时单机 QPS 从 600 提升至 4000 左右，基本达到了上线前的性能预期，为了确认压测下是否还有模板的编译动作，我们继续在 Node.js 性能平台上抓取压测期间 3 分钟的 CPU Profile：可以看到上述对 koa-ejs 模板进行优化后，ejs.compile 确实消失了，而压测期间不再有大量重复且耗费 CPU 的编译动作后，应用整体的性能比最开始有了 20 倍左右的提升。文中 koa-ejs 模块缓存问题已经在 4.1.2 版本（包含）之后被修复了，详情可以见 cache include file，如果大家使用的 koa-ejs 版本 >= 4.1.2 就可以放心使用。结尾 CPU Profile 本质上以可读的方式反映给开发者运行时的 JavaScript 代码执行频繁程度，除了在线上进程出现负载很高时能够用来定位问题代码之外，它在我们上线前进行性能压测和对应的性能调优时也能提供巨大的帮助。这里需要注意的是：仅当进程 CPU 负载非常高的时候去抓取得到的 CPU Profile 才能真正反馈给我们问题所在。在这个源自真实生产的案例中，我们也可以看到，正确和不正确地去使用 Node.js 开发应用其前后运行效率能达到二十倍的差距，Node.js 作为一门服务端技术栈发展至今日，其本身能够提供的性能是毋庸置疑的，绝大部分情况下执行效率不佳是由我们自身的业务代码或者三方库本身的 Bug 引起的，Node.js 性能平台则可以帮助我们以比较方便的方式找出这些 Bug。

发表了文章 2019-03-23

Node.js 应用故障排查手册 —— Node.js 性能平台使用指南

楔子前一节中我们借助于 Chrome devtools 实现了对线上 Node.js 应用的 CPU/Memory 问题的排查定位，但是在实际生产实践中，大家会发现 Chrome devtools 更加偏向本地开发模式，因为显然 Chrome devtools 不会负责去生成分析问题所需要的 Dump 文件，这意味着开发者还得额外在线上项目中设置好 v8-profiler 和 heapdump 这样的工具，并且通过额外实现的服务来能够去对线上运行的项目进行实时的状态导出。加上实际上预备章中除了 CPU/Memory 的问题，我们还会遇到一些需要分析错误日志、磁盘和核心转储文件等才能定位问题的状况，因此在这些场景下，仅仅靠 Chrome devtools 显然会有一些力不从心。正是为了解决广大 Node.js 开发者的这些痛点，我们在这里推荐大家在使用 Node.js 性能平台，即原来的 AliNode，它已经在阿里巴巴集团内部承载了几乎所有的 Node.js 应用线上运行监控和问题排查，因此大家可以放心在生产环境部署使用。本节将从 Node.js 性能平台的设计架构、核心能力以及最佳实践等角度，帮助开发者更好地使用这一工具来解决前面提到的异常指标分析和线上 Node.js 应用故障定位。本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。架构 Node.js 性能平台其实简单的说由三部分组成：云控制台 + AliNode runtime + Agenthub，如下图所示：具体的部署步骤可以查看官方文档：自助式部署 Runtime。借助于 Node.js 性能平台的整套解决方案，我们可以很方便地实现预备章节中提到的绝大部分异常指标的告警分析的能力。在生产实践过程中，实际上在笔者看来，Node.js 性能平台解决方案其实仅仅是提供了三个最核心却也是最有效的能力：异常指标告警，即预备节中一些异常指标出现异常时能通过短信/钉钉通知到开发者导出线上 Node.js 应用状态，包括但不限于即前面 Chrome devtools 一节中提到的 CPU/Memory 状态导出在线分析结果和更好的 UI 展示，定制化解析应用导出状态和展示，更符合国内开发者习惯换言之，Node.js 性能平台作为一个产品本身功能也在不断迭代新增修改中，但是以上的三个核心能力一定是第一优先级保障的，其它边边角角的功能则相对来说响应优先级没有那么高。实际上我们也理解作为使用平台的开发者希望能在一个地方看到 Node.js 线上应用从底层到业务层的所有细节，然而我个人感觉不同的工具都有应该有其核心的能力输出，很多时候不断做加法容易让产品本身定位模糊化以及泛而不精，Node.js 性能平台实际上始终在致力于让原本线上黑盒的运行时状态，能更加直观地反馈给开发者，让 Node.js 应用的开发者面对一些偏向底层的线上疑难杂症能够不再无所适从。最佳实践 I. 配置合适的告警线上应用的告警实际上是一种自我发现问题的保护机制，如果没有告警能力，那每次都会等到问题暴露到用户侧导致其反馈才能发现问题，这显然对用户体验非常的不友好。因此部署完成一个项目后，开发者首先需要去配置合适的告警，而在我们的生产实践中，线上问题通过错误日志、Node.js 进程 CPU/Memory 的分析、核心转储（Core dump）的分析以及磁盘分析能够得出结论，因此我们需要的基本的告警策略也是源自以上五个部分。幸运的是平台已经给我们预设好了这些告警，大家只需要选择一下即可完整这里的告警配置，如下图所示：在 Node.js 性能平台的告警页面上有快速添加规则，点开选中后会自动生成告警规则的阈值表达式模板和报警说明模板，我们可以按照项目实际监控需求进行修改，比如想要对 Node.js 进程的堆内存进行监控，可以选中 Memory 预警选项，如下图所示：此时点击添加报警项即完整了对进程堆内存的告警，并且将出现告警时需要点击通知设置->添加到联系人列表来添加的联系人加入此条规则，如下图所示：那么在例子中的这条默认的规则里，当我们的 Node.js 进程分配的堆内存超过堆上线的 80%（默认 64 位机器上堆上限是 1.4G）时会触发短信通知到配置绑定到此条规则的联系人。实际上快速添加规则列表中给大家提供的是最常见的一些预配置好的告警策略，如果这些尚不能满足你的需求，更多定制化的自定义的服务告警策略配置方法可以看官方文档报警设置。并且除了短信告警，也支持钉钉机器人推送告警消息到群，方便群发感知线上 Node.js 应用态势。 II. 按照告警类型进行分析按照 I 节中配置完成合适的告警规则后，那么当收到告警短信时就可以按照策略类型进行对应的分析了。本节将按照预备节中比较常见的五大类问题来逐一讲解。 a. 磁盘监控这个是比较好处理的问题，在快速添加的规则里实际上我们会在服务器的磁盘使用超过 85% 时进行告警，那么收到磁盘告警后，可以连接到服务器，使用如下命令查看那个目录占用比较高： sudo du -h --max-depth=1 / 找到占比比较高的目录和文件后，看看是否需要备份后删除来释放出磁盘空间。 b. 错误日志收到特定的错误日志告警后，只需要去对应的项目的 Node.js 性能平台控制台找到问题实例去查看其异常日志即可，如下图所示：这里会按照错误类型进行规整，大家可以结合展示的错误栈信息来进行对应的问题定位。注意这里的错误日志文件需要你在部署 Agenthub 的时候写入配置文件，详细可以参见文档配置和启动 Agenthub 一节中的详细配置内容。 c. 进程 CPU 高终于到了前一节中借助 v8-profiler 导出 CPU Profile 文件再使用 Chrome devtools 进行分析的异常类型了。那么在 Node.js 性能平台的整套解决方案下，我们并不需要额外的去依赖类似 v8-profiler 这样的第三方库来实现进程状态的导出，与此相对的，当我们收到 Node.js 应用进程的 CPU 超过我们设置的阈值告警时，我们只需要在控制台对应的实例点击 CPU Profile 按钮即可：默认会给抓取的进程生成 3 分钟的 CPU Profile 文件，等到结束后生成的文件会显示在文件页面：此时点击转储即可上传到云端以供在线分析展示了，如下图所示：这里可以看到有两个分析按钮，其实第二个下标带有 (devtools) 的分析按钮实际上就是前一节中提到的 Chrome devtools 分析，这里不再重复讲解了，如果有遗忘的同学可以再去回顾下本大章前一节的内容。我们重点看下第一个 AliNode 定制的分析，点击第一个分析按钮后，可以在新页面看到如下所示内容：这里其实也是火焰图，但与 Chrome devtools 提供的火焰图不一样的地方在于，这里是将抓取的 3 分钟内的 JS 函数执行进行了聚合展示出来的火焰图，在一些存在多次执行同一个函数（可能每次执行非常短）的情况下，聚合后的火焰图可以很方便的帮助我们找到代码的执行瓶颈来进行对应的优化。值得一提的是，如果你使用的 AliNode runtime 版本在 v3.11.4 或者 v4.2.1 以上（包含这两个版本）的话，当你的应用出现类死循环问题，比如由于异常的用户参数导致的正则回溯（即执行完这个正则要十几年，类似于 Node.js 进程发生了死循环）这类问题时，可以通过抓取 CPU Profile 文件来很方便地定位到问题代码，详细信息有兴趣的同学可以看下 Node.js 性能平台支持死循环和正则攻击定位。 d. 内存泄漏与 CPU 高的问题一样，当我们收到 Node.js 应用进程的堆内存占据堆上限的比率超过我们设置的阈值时，我们也不需要类似 heapdump 这样的第三方模块来导出堆快照进行分析，我们还是在控制台对应的实例点击堆快照按钮即可生成对应 Node.js 进程的堆快照：生成的堆快照文件同样会显示在文件列表页面，点击转储将堆快照上传至云端以供接下来的分析：与上面一样，下标带有 (devtools) 的分析按钮还是前一节中提到的 Chrome devtools 分析，这里还是着重解析下 AliNode 定制的第一个分析按钮，点击后新页面如下图所示：首先解释下上面的总览栏目的内容信息：文件大小：堆快照文件本身的大小 Shallow Szie 总大小：回顾下上一节中的内容，GC 根的 Retained Size 大小其实就是堆大小，也等于堆上分配的所有对象的 Shallow Size 总大小，因此这里其实就是已使用的堆空间对象个数：当前堆上分配的 Heap Object 总个数对象边个数：这个稍微抽象一些，假如 Object A.b 指向另一个 Object B，我们则认为表示指向关系的 b 属性就是一条边 GC Roots 个数： V8 引擎实现的堆分配，其实并不是我们之前为了帮助大家理解简化的只有一个 GC 根的情况，在实际的运行模型下，堆空间内存在许多的 GC 根，这里是真实的 GC 根的个数这部分的信息旨在给大家一个概览，部分信息需要深入解读堆快照才能彻底理解，如果你实在无法理解其中的几个概览指标信息，其实也无伤大雅，因为这并不影响我们定位问题代码。简单了解了概览信息的含义后，接着我们来看对于定位 Node.js 应用代码段非常重要的信息，第一个是默认展示的可疑点信息，上图中的内容表示 @15249 这个对象占据了堆空间 97.41% 的内存，那么它很可能就是一个泄漏对象，这里又存在两种可能：此对象本身应该被释放但是却没有释放，造成堆空间占用如此大此对象的某些属性应该被释放但是却没有释放，造成表象是此对象占据大量的堆空间要判断是哪一种情况，以及追踪到对应的代码段，我们需要点击图中的簇视图链接进行进一步观察：这里继续解释下什么是簇视图，簇视图实际上是支配树的一个别名，也就是这个视图下我们看到的正是前面一节中提到的从可疑泄漏对象出发的支配树视图，它的好处是，在这个视图下，父节点的 Retained Size 可以直接由其子节点的 Retained Size 累加后再加上父节点自身的 Shallow Size 得到，换言之，在这个视图下我们层层展开即可以看到可疑泄漏对象的内存究竟被哪些子节点占用了。并且结合前一节的支配树描述，我们可以知道支配树下的父子节点关系，并不一定是真正的堆上空间内的对象父子关系，但是对于那些支配树下父子关系在真正的堆空间内也存在父子节点关系的簇节点，我们将真正的边也用浅紫色标识出来，这部分的边信息对于我们映射到真正的代码段非常有帮助。在这个简单的例子中，我们可以很清晰的看到可疑泄漏对象 @15249 实际上是下属的 test-alinode.js 中存在一个 array 变量，其中存储了四个 45.78 兆的数组导致的问题，这样就找到了问题代码可以进行后续优化。而在实际生产环境的堆快照分析下，很多情况下簇视图下的父子关系在真实的堆空间中并不存在，那么就不会有这些紫色的边信息展示，这时候我们想要知道可疑泄漏对象如何通过 JavaScript 生成的对象间引用关系引用到后面真正占据掉堆空间的对象（比如上图中的 40 多兆的 Array 对象），我们可以点击可疑节点自身的地址链接：这样就进入到以此对象为起点的堆空间内真正的对象引用关系视图 Search 视图：这个视图因为反映的是堆空间内各个 Heap Object 之间真正的引用连接关系，因此父对象的 Retained Size 并不能直接由子节点的 Retained Size 累加获取，如上图红框内的内容，显然这里的三个子节点 Retained Size 累加已经超过 100%，这也是 Search 视图和簇视图很大的不同点。借助于 Search 视图，我们可以根据其内反映出来的对象和边之间的关系来定位可疑泄漏对象具体是在我们的 JavaScript 代码中的哪一部分生成。其实看到这边，一些读者应该意识到了这里的 Search 视图实际上对应的就是前一节中提到的 Chrome devtools 的 Containment 视图，只不过这里的起始点是我们选中的对象本身罢了。最后就是需要提一下 Retainers 视图，它和前一节中提到的 Chrome devtools 中解析堆快照展示结果里面的 Retainers 含义是一致的，它表示对象的父引用关系链，我们可以来看下：这里 globa@1279 对象的 clearImmediate 属性指向 timers.js()@15325，而 timers.js()@15325 的 context 属性指向了可疑的泄漏对象 system / Context@15249。在绝大部分的情况下，通过结合 Search 视图和 Retainers 视图我们可以定位到指定对象在 JavaScript 代码中的生成位置，而簇视图下我们又可以比较方便的知道堆空间被哪些对象占据掉了，那么综合这两部分的信息，我们就可以实现对线上内存泄漏的问题进行分析和代码定位了。 e. 出现核心转储最后就是收到服务器生成核心转储文件（Core dump 文件）的告警了，这表示我们的进程已经出现了预期之外的 Crash，如果你的 Agenthub 配置正常的话，在文件 -> Coredump 文件页面会自动将生成的核心转储文件信息展示出来：和之前的步骤类似，我们想要看到服务端分析和结果展示，首先需要将服务器上生成的核心转储文件转储到云端，但是与之前的 CPU Profile 和堆快照的转储不一样的地方在于，核心转储文件的分析需要我们提供对应 Node.js 进程的启动执行文件，即 AliNode runtime 文件，这里简化处理为只需要设置 Runtime 版本即可：点击设置 runtime 版本即可进行设置，格式为 alinode-v{x}.{y}.{z} 的形式，比如 alinode-v3.11.5，版本会进行校验，请务必填写你的应用真实在使用的 AliNode runtime 版本。版本填写完成后，我们就可以点击转储按钮进行文件转储到云端的操作了：显然对于核心转储文件来说，Chrome devtools 是没有提供解析功能的，所以这里只有一个 AliNode 定制的分析按钮，点击这个分析按钮，即可以看到结果：这里第一栏的概览信息看文字描述就能理解其含义，所以这里就不再多做解释了，我们来看下比较重要的默认视图 BackTrace 信息视图，此视图下展示的实际上是 Node.js 应用在 Crash 时刻的线程信息，许多开发者认为 Node.js 是单线程的运行模型，其实这句话也不是完全错误，更准确的说法是单主 JavaScript 工作线程，因为实际上 Node.js 还会开启一些后台线程来处理诸如 GC 里的部分任务。绝大部分的情况下，应用的 Crash 都是由 JavaScript 工作线程引发的，因此我们需要关注的也仅仅是这个线程，这里显然 BackTrace 信息视图中将 JavaScript 工作线程做了标红和置顶处理，展开后可以看到 Node.js 应用 Crash 那一刻的错误堆栈信息：因为就算在 JavaScript 的工作线程中，也会存在 Native C/C++ 代码的穿透，但是在问题排查中我们往往只需要去看同样标红的 JavaScript 栈信息即可，像在这个简单的例子中，显然 Crash 是因为视图去启动一个不存在的 JS 文件导致的。值得一提的是，核心转储文件的分析功能非常的强大，因为在预备节中我们提到其生成的途径除了 Node.js 应用 Crash 的时候由系统内核控制输出外，还可以由 gcore 这样的命令手动强制输出，而本小节我们又看到核心转储文件的分析实际上可以看到此刻的 JavaScript 栈信息以及其入参，结合这两点，我们可以在线上出现 CPU Profile 一节中提到的类死循环问题时直接采用 gcore 生成核心转储文件，然后上传至平台云端进行分析，这样不仅可以看到我们的 Node.js 应用是阻塞在哪一行的 JavaScript 代码，甚至引发阻塞的参数我们也能完整获取到，这对本地复现定位问题的帮助无疑是无比巨大的。结尾本节其实给大家介绍了 Node.js 性能平台的整套面向 Node.js 应用开发的监控、告警、分析和定位问题的解决方案的架构和最佳实践，希望能让大家对平台的能力和如何更好地结合自身项目进行使用有一个整体的理解。限于篇幅，最佳实践中的 CPU Profile、堆快照和核心转储文件的分析例子都非常的简单，这部分的内容也更多的是旨在帮助大家理解平台提供的工具如何使用以及其分析结果展示的指标含义，那么本书的第三节中，我们会通过一些实际的生产遇到的案例问题借助于 Node.js 性能平台提供的上述工具分析过程，来帮助大家更好的理解这部分信息，也希望大家在读完这些内容后能有所收获，能对 Node.js 应用在生产中的使用更有信心。

发表了文章 2019-03-23

Node.js 应用故障排查手册 —— 正确打开 Chrome devtools

楔子前面的预备章节中我们大致了解了如何在服务器上的 Node.js 应用出现问题时，从常规的错误日志、系统/进程指标以及兜底的核心转储这些角度来排查问题。这样就引出了下一个问题：我们知道进程的 CPU/Memory 高，或者拿到了进程 Crash 后的核心转储，要如何去进行分析定位到具体的 JavaScript 代码段。其实 Chrome 自带的 Devtools，对于 JavaScript 代码的上述 CPU/Memory 问题有着很好的原生解析展示，本节会给大家做一些实用功能和指标的介绍（基于 Chrome v72，不同的版本间使用方式存在差异）。本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。 CPU 飙高问题 I. 导出 JS 代码运行状态当我们通过第一节中提到的系统/进程指标排查发现当前的 Node.js 应用的 CPU 特别高时，首先我们需要去通过一些方式将当前 Node.js 应用一段时间内的 JavaScript 代码运行状况 Dump 出来，这样子才能分析知道 CPU 高的原因。幸运的是，V8 引擎内部实现了一个 CPU Profiler 能够帮助我们完成一段时间内 JS 代码运行状态的导出，目前也有不少成熟的模块或者工具来帮我们完成这样的操作。 v8-profiler 是一个老牌的 Node.js 应用性能分析工具，它可以很方便地帮助开发者导出 JS 代码地运行状态，我们可以在项目目录执行如下命令安装此模块： npm install v8-profiler --save 接着可以在代码中按照如下方式获取到 5s 内地 JS 代码运行状态： 'use strict'; const v8Profiler = require('v8-profiler'); const title = 'test'; v8Profiler.startProfiling(title, true); setTimeout(() => { const profiler = v8Profiler.stopProfiling(title); profiler.delete(); console.log(profiler); }, 5000); 那么我们可以看到，v8-profiler 模块帮我导出的代码运行状态实际上是一个很大的 JSON 对象，我们可以将这个 JSON 对象序列化为字符串后存储到文件：test.cpuprofile 。注意这里的文件名后缀必须为 .cpuprofile ，否则 Chrome devtools 是不识别的。注意：v8-profiler 目前也处于年久失修的状态了，在 Node.js 8 和 Node.js 10 上已经无法正确编译安装了，如果你在 8 或者 10 的项目中想进行使用，可以试试看 v8-profiler-next。 II. 分析 CPU Profile 文件借助于 v8-profiler 拿到我们的 Node.js 应用一段时间内的 JS 代码运行状态后，我们可以将其导入 Chrome devtools 中进行分析展示。在 Chrome 72 中，分析我们 Dump 出来的 CPU Profile 的方法已经和之前有所不同了，默认工具栏中也不会展示 CPU Profile 的分析页面，我们需要通过点击工具栏右侧的更多按钮，然后选择 More tools -> JavaScript Profiler 来进入到 CPU 的分析页面，如下图所示：选中 JavaScript Profiler 后，在出现的页面上点击 Load 按钮，然后将刚才保存得到的 test.cpuprofile 文件加载进来，就可以看到 Chrome devtools 的解析结果了：这里默认的视图是 Heavy 视图，在这个视图下，Devtools 会按照对你的应用的影响程度从高到低，将这些函数列举出来，点击展开能够看到这些列举出来的函数的全路径，方便你去代码中对应的位置进行排查。这里解释两个比较重要的指标，以便让大家能更有针对性地进行排查： Self Time: 此函数本身代码段执行地时间（不包含任何调用） Total Time: 此函数包含了其调用地其它函数总共的执行时间像在上述地截图例子中，ejs 模块在线上都应该开启了缓存，所以 ejs 模块的 compile 方法不应该出现在列表中，这显然是一个非常可疑的性能损耗点，需要我们去展开找到原因。除了 Heavy 视图，Devtools 实际上还给我们提供了火焰图来进行更多维度的展示，点击左上角可以切换：火焰图按照我们的 CPU 采样时间轴进行展示，那么在这里我们更容易看到我们的 Node.js 应用在采样期间 JS 代码的执行行为，新增的两个指标这边也给大家解释一下其含义： Aggregated self time: 在 CPU 采样期间聚合后的此函数本身代码段的执行总时间（不包含其他调用） Aggregated total time: 在 CPU 采样期间聚合后的此函数包含了其调用地其它函数总共的执行总时间综上，借助于 Chrome devtools 和能够导出当前 Node.js 应用 Javascript 代码运行状态的模块，我们已经可以比较完备地对应用服务异常时，排查定位到相应的 Node.js 进程 CPU 很高的情况进行排查和定位分析了。在生产实践中，这部分的 JS 代码的性能的分析往往也会用到新项目上线前的性能压测中，有兴趣的同学可以更深入地研究下。内存泄漏问题 I. 判断是否内存泄漏在笔者的经历中，内存泄漏问题是 Node.js 在线上运行时出现的问题种类中的重灾区。尤其是三方库自身的 Bug 或者开发者使用不当引起的内存泄漏，会让很多的 Node.js 开发者感到束手无策。本节首先向读者介绍下，什么情况下我们的应用算是有很大的可能在发生内存泄漏呢？实际上判断我们的线上 Node.js 应用是否有内存泄漏也非常简单：借助于大家各自公司的一些系统和进程监控工具，如果我们发现 Node.js 应用的总内存占用曲线处于长时间的只增不降，并且堆内存按照趋势突破了堆限制的 70% 了，那么基本上应用很大可能产生了泄漏。当然事无绝对，如果确实应用的访问量（QPS）也在一直增长中，那么内存曲线只增不减也属于正常情况，如果确实因为 QPS 的不断增长导致堆内存超过堆限制的 70% 甚至 90%，此时我们需要考虑的扩容服务器来缓解内存问题。 II. 导出 JS 堆内存快照如果确认了 Node.js 应用出现了内存泄漏的问题，那么和上面 CPU 的问题一样，我们需要通过一些办法导出 JS 内存快照（堆快照）来进行分析。V8 引擎同样在内部提供了接口可以直接将分配在 V8 堆上的 JS 对象导出来供开发者进行分析，这里我们采用 heapdump 这个模块，首先依旧是执行如下命令进行安装： npm install heapdump --save 接着可以在代码中按照如下方法使用此模块： 'use sytrict'; const heapdump = require('heapdump'); heapdump.writeSnapshot('./test' + '.heapsnapshot'); 这样我们就在当前目录下得到了一个堆快照文件：test.heapsnapshot ，用文本编辑工具打开这个文件，可以看到其依旧是一个很大的 JSON 结构，同样这里的堆快照文件后缀必须为 .heapsnapshot ，否则 Chrome devtools 是不识别的。 III. 分析堆快照在 Chrome devtools 的工具栏中选择 Memory 即可进入到分析页面，如下图所示：然后点击页面上的 Load 按钮，选择我们刚才生成 test.heapsnapshot 文件，就可以看到分析结果，如下图所示：默认的视图其实是一个 Summary 视图，这里的 Constructor 和我们编写 JS 代码时的构造函数并无不同，都是指代此构造函数创建的对象，新版本的 Chrome devtools 中还在构造函数后面增加 * number 的信息，它代表这个构造函数创建的实例的个数。实际上在堆快照的分析视图中，有两个非常重要的概念需要大家去理解，否则很可能拿到堆快照看着分析结果也无所适从，它们是 Shallow Size 和 Retained Size ，要更好地去理解这两个概念，我们需要先了解支配树。首先我们看如下简化后的堆快照描述的内存关系图：这里的 1 为根节点，即 GC 根，那么对于对象 5 来说，如果我们想要让对象 5 回收（即从 GC 根不可达），仅仅去掉对象 4 或者对象 3 对于对象 5 的引用是不够的，因为显然从根节点 1 可以分别从对象 3 或者对象 4 遍历到对象 5。因此我们只有去掉对象 2 才能将对象 5 回收，所以在上面这个图中，对象 5 的直接支配者是对象 2。照着这个思路，我们可以通过一定的算法将上述简化后的堆内存关系图转化为支配树：对象 1 到对象 8 间的支配关系描述如下：对象 1 支配对象 2 对象 2 支配对象 3 、4 和 5 对象 4 支配对象 6 对象 5 支配对象 7 对象 6 支配对象 8 好了，到这里我们可以开始解释什么是 Shallow Size 和 Retained Size 了，实际上对象的 Shallow Size 就是对象自身被创建时，在 V8 堆上分配的大小，结合上面的例子，即对象 1 到 8 自身的大小。对象的 Retained Size 则是把此对象从堆上拿掉，则 Full GC 后 V8 堆能够释放出的空间大小。同样结合上面的例子，支配树的叶子节点对象 3、对象 7 和对象 8 因为没有任何直接支配对象，因此其 Retained Size 等于其 Shallow Size。将剩下的非叶子节点可以一一展开，为了篇幅描述方便，SZ_5表示对象 5 的 Shallow Size，RZ_5 表示对象 5 的 Retained Size，那么可以得到如下结果：对象 3 的 Retained Size：RZ_3 = SZ_3 对象 7 的 Retained Size：RZ_7 = SZ_7 对象 8 的 Retained Size：RZ_8 = SZ_8 对象 6 的 Retained Size：RZ_6 = SZ_6 + RZ_8 = SZ_6 + SZ_8 对象 5 的 Retained Size：RZ_5 = SZ_5 + RZ_7 = SZ_5 + SZ_7 对象 4 的 Retained Size：RZ_4 = SZ_4 + RZ_6 = SZ_4 + SZ_6 + SZ_8 对象 2 的 Retained Size：RZ_2 = SZ_2 + RZ_3 + RZ_4 + RZ_5 = SZ_2 + SZ_3 + SZ_4 + SZ_5 + SZ_6 + SZ_7 + SZ_8 GC 根 1 的 Retained Size：RZ_1 = SZ_1 + RZ_2 = SZ_1 + SZ_2 + RZ_3 + RZ_4 + RZ_5 = SZ_2 + SZ_3 + SZ_4 + SZ_5 + SZ_6 + SZ_7 + SZ_8 这里可以发现，GC 根的 Retained Size 等于堆上所有从此根出发可达对象的 Shallow Size 之和，这和我们的理解预期是相符合的，毕竟将 GC 根从堆上拿掉的话，原本就应当将从此根出发的所有对象都清理掉。理解了这一点，回到我们最开始看到的默认总览视图中，正常来说，可能的泄漏对象往往其 Retained Size 特别大，我们可以在窗口中依据 Retained Size 进行排序来对那些占据了堆空间绝大部分的对象进行排查：假如确认了可疑对象，Chrome devtools 中也会给你自动展开方便你去定位到代码段，下面以 NativeModule 这个构造器生成的对象 vm 为例：这里上半部分是顺序的引用关系，比如 NativeModule 实例 @45655 的 exports 属性指向了对象 @45589，filename 属性则指向一个字符串 "vm.js"；下半部分则是反向的引用关系：NativeModule 实例 @13021 的 _cache 属性指向了 Object 实例 @41103，而 Object 实例 @41103 的 vm 属性指向了 NativeModule 实例 @45655。如果对这部分展示图表比较晕的可以仔细看下上面的例子，因为找到可疑的泄漏对象，结合上图能看到此对象下的属性和值及其父引用关系链，绝大部分情况下我们就可以定位到生成可疑对象的 JS 代码段了。实际上除了默认的 Summary 视图，Chrome devtools 还提供了 Containment 和 Statistics 视图，这里再看下 Containment 视图，选择堆快照解析页面的左上角可以进行切换，如下图所示：这个视图实际上是堆快照解析出来的内存关系图的直接展示，因此相比 Summary 视图，从这个视图中直接查找可疑的泄漏对象相对比较困难。结尾 Chrome devtools 实际上是非常强大的一个工具，本节也只是仅仅介绍了对 CPU Profile 和堆快照解析能力的介绍和常用视图的使用指南，如果你仔细阅读了本节内容，面对服务器上定位到的 Node.js 应用 CPU 飙高或者内存泄漏这样的问题，想必就可以做到心中有数不慌乱了。

发表了文章 2019-03-23

Node.js 应用故障排查手册 —— 大纲与常规问题指标简介

楔子你是否想要尝试进行 Node.js 应用开发但是又总听人说它不安全、稳定性差，想在公司推广扩张大前端的能力范畴和影响又说服不了技术领导。 JavaScript 发展到今天，早已脱离原本浏览器的战场，借助于 Node.js 的诞生将其触角伸到了服务端、PC 跨平台客户端方案等各个领域，但是与此同时，JS Runtime 对于绝大部分的开发者来说又一如既往的处于黑盒状态——开发者无法感知其运行状态，出现一些性能、内存问题时也没有很好的工具链进行更深入的支持。本书将在基于 Node.js 性能平台的基础上，从多个大家开发上线过程中可能遇到的疑难杂症的视角，观察如何去发现、定位和解决这些问题，帮助读者构建对 Node.js 这门语言的更多信心。因为本书将属于 Node.js 开发进阶的内容，因此我们希望本书的读者具备以下的基本技能：常规的 Node.js 应用开发的能力常规的服务器性能指标参数的理解，比如 CPU、Memory、Load、文件打开数等常见的数据库、缓存等操作负载均衡、多进程模型如果使用容器，容器的基本知识，资源管理等本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。常规排查的指标当我们第一次遇到线上异常时，很多人会感觉无从下手。本节作为预备篇，将从服务器异常时常见的排查指标开始，帮助大家建立一个更加直观的问题处理体系。毕竟如果我们面对线上异常时，如果连系统哪里有问题都不知道，那么后续的借助 Node.js 性能平台更深入定位问题代码就更加无从谈起了。错误日志当我们的应用出现问题时，首先需要去查看我们应用的错误日志，观察在这段时间内是不是有错误在一直抛出，导致了我们的服务不稳定。这一块的信息显然是因各个应用而异的，当我们的项目比较大（Ecs/Docker 节点比较多）的时候，就需要对错误日志的进行统一的采集收集来保证出问题时的快速定位。一个比较简单的统一日志平台可以设计如下：其中的采集服务器和 Agent 上报之间一般会采用消息队列（Kafka）来作为缓冲区减轻双方的负载，ELK 就是一个比较成熟的日志服务。有了统一的日志平台后，当我们的应用出现问题时，首先应该去日志平台上查看当前的错误日志信息，特别是对于那些在频繁出现的错误日志应当引起警惕，需要去仔细地结合产生错误的代码段进行回溯确认是否是造成当前服务不稳定的元凶，Node.js 性能平台也实现了一个简单的错误日志回溯 + 告警的系统，本书第二部分会更详细说明。系统指标如果在上述的错误日中没有看到可疑的信息（实际上错误日志以及本节的系统指标排查先后顺序并无固定，大家可以视自己的需求进行），那么接下来我们就应该关注下问题是不是因为服务器或者 Node.js 应用本身的负载到了极限导致的问题。一些比较常见的大家需要关注的系统指标如下所示： CPU & Memory Disk 磁盘占用率 I/O 负载 TCP 连接状态下面逐一讲解这些可能存在问题的系统指标。 I. CPU & Memory 使用 top 命令来观察和 Node.js 应用进程的 CPU 和 Memory 负载情况。一般来说，对于 CPU 很高 Node.js 进程，我们可以使用 Node.js 性能平台提供的 CPU Profiling 工具来在线 Dump 出当前的 Javascript 运行情况，进而找到热点代码进行优化，具体在本书第二部分会有更详细地说明。那么对于 Memory 负载很高的情况，正常来说就是发生了内存泄漏（或者有预期之外的内存分配导致溢出），那么同样的我们可以用性能平台提供的工具来在线 Dump 出当前的 Javascript 堆内存和服务化的分析来结合你的业务代码找到产生泄漏的逻辑。这里需要注意的是，目前性能平台能够进行详尽分析的地方集中在你的 JS 代码上，对于完全是 C++ 扩展执行的或者完全的 V8/Libuv 底层执行（这部分功能后面会补上）的逻辑，以及不分配在 V8 Heap 上的内存，性能平台目前没有更好的办法来进行分析处理。而实际上在我们遇到的案例中，大家编写的 JS 代码出问题占了绝大部分，也就是性能平台目前针对 JS 部分比较完善的在线 Dump + 服务化分析基本上能够解决开发者 95% 甚至以上的问题了。 II. Disk 磁盘占用率使用 df 命令可以观察当前的磁盘占用情况，这个也是非常常见的问题，很多开发者会忽略对服务器磁盘的监控告警，当我们的日志/核心转储等大文件逐渐将磁盘打满到 100% 的时候，Node.js 应用很可能会无法正常运行，Node.js 性能平台目前也提供了对磁盘的监控，在本书第二部分同样会有更详细地说明。 III. I/O 负载使用 top/iostat 和 cat /proc/${pid}/io 来查看当前的 I/O 负载，这一项的负载很高的话，也会使得 Node.js 应用出现卡死等情况。 IV. TCP 连接状态绝大部分的 Node.js 应用实际上是 Web 应用，每个用户的连接都会创建一个 Socket 连接，在一些异常情况下（比如遭受半连接攻击或者内核参数设置不合理），服务器上会有大量的 TIME_WAIT 状态的连接，而大量的 TIME_WAIT 积压会导致 Node.js 应用的卡死（内核无法为新的请求分配创建新的 TCP 连接），我们可以使用 netstat -ant|awk '/^tcp/ {++S[$NF]} END {for(a in S) print (a,S[a])}' 命令来确认这个问题。核心转储（Core dump）线上 Node.js 应用故障往往也伴随着进程的 Crash，借助于一些守护进程的自检重启拉起，我们的服务依旧在运行，但是我们不应该去忽略这些意外的 Crash —— 当流量增大或者造成服务器的问题用户访问被别有用心之人抓住时，我们集群就变得岌岌可危了。绝大部分情况下，会造成 Node.js 应用 Crash 掉的错误日志往往并不会记录到我们的错误日志文件中，幸运的是，服务器内核提供了一项机制帮助我们在应用 Crash 时自动地生成核心转储（Core dump）文件，让开发者可以在事后进行分析还原案发现场。核心转储核心转储（Core dump）实际上是我们的应用意外崩溃终止时，计算机自动记录下进程 Crash 掉那一刻的内存分配信息、Program counter 以及堆栈指针等关键信息来生成核心转储文件，因此获取到核心转储文件后，我们可以通过 MDB、GDB、LLDB 等工具即可实现解析诊断实际进程的 Crash 原因。生成文件触发核心转储生成转储文件目前主要有两种方式： I. 设置内核参数使用 ulimit -c unlimited 打开内核限制，并且考虑到默认运行模式下，Node.js 对 JS 造成的 Crash 是不会触发核心转储动作的，因此我们可以在 Node 应用启动时加上参数 --abort-on-uncaught-exception 来对出现未捕获的异常时也能让内核触发自动的核心转储动作。 II. 手动调用手动调用 gcore <pid> （可能需要 sudo 权限）的方式来手动生成，因为此时 Node.js 应用依旧在运行中，所以实际上这种方式一般用于「活体检验」，用于 Node.js 进程假死状态下的问题定位。这里需要注意的是，以上的生成核心转储的操作都并没有那么安全务必记得对服务器磁盘进行监控和告警**。获取到 Node.js 应用生成的核心转储文件后，我们可以借助于 Node.js 性能平台提供的在线 Core dump 文件分析功能进行分析定位进程 Crash 的原因了，具体用法会在本书第二部分进行说明。小结本节从常见的几个服务器问题点，给大家对线上 Node.js 应用出现故障时如何去排查定位有了一些大概的印象，本章也是后续内容的一个预备知识，了解了这部分内容，才能在后面的一些实战案例中明白为何我们忽略了其它而选择详尽地服务化分析其中的一些要点。而核心转储的深入分析则能够帮助我们解决 Node.js 应用的绝大部分底层故障，因为其可以还原出问题 JavaScript 代码和引发问题的参数，功能非常地强大。

发表了文章 2018-10-19

如何进行 GC 调优提升 Node 应用性能

前情用户项目上线进行压测时，CPU 100% 时单进程 QPS 在 100 上下浮动，想进行一些进一步的优化。经过接入 Node.js 性能平台后，在压测试做 CPU Profile 观察系统 CPU 耗费在什么地方：可以看到 _tickDomainCallback 和 garbage collector 在 CPU 的占比加起来高达 83%，而经过和用户沟通，发现 _tickDomainCallback 内部的耗费 CPU 高的逻辑分别是 typeorm 和自己的 controller 逻辑，typeorm 方面因为 api 变动的原因不太方便升级，controller 逻辑则是已经优化过了暂时没有提升的空间。因此很自然的，我们会把进一步提升项目性能的目光放到 GC 阶段。这里在 3min 的 CPU 采样期间，GC 阶段的调用占比高达 27.5%，结合当时的性能平台监控数据，我们可以看到绝大部分都是 scavenge 阶段，此时继续进行线上压测，同时做 GC Trace 来获取更多 GC 阶段的详细信息：在 GC Trace 结果分析图中，可以看到红圈起来的几个重要信息： GC 总暂停时间高达 47.8s，大头是 scavenge 3min 的 GC 追踪日志里面，总共进行了 988 次的 scavenge 回收每次 scavenge 耗时均值在 50 ~ 60ms 之间分析上面对 GC Trace 结果的分析中，可以看到此次 GC 优化的点集中在 scavenge 回收阶段，即新生代的内存回收。那么通过翻阅 V8 的 scavenge 回收逻辑可以知道，这个阶段触发回收的条件是：semi space allocation failed。这样就可以推测，用户的应用在压测期间应该是在新生代频繁生成了大量的小对象，导致默认的 semi space 总是处于很快被填满从而触发 flip 的状态，这才会出现在 GC 追踪期间这么多的 scavenge 回收和对应的 CPU 耗费。面对这样的情况，我们是不是可以通过调整默认的 semi space 的值来进行优化呢？优化 V8 的代码查看后发现默认的 semi space 的值为 16M（alinode-v3.11.3/node-v8.11.3），经过和用户沟通，我们打算分别调整为 64M、128M 和 256M 来进行观察，可以通过在 node 启动应用时加上 --max_semi_space_size 的 flag 来生效。 I. semi space 设置为 64M 将 semi space 调整为 64M 后，进行线上压测，并且在压测期间获取 CPU Profile 和 GC Trace，如下图所示：可以看到 garbage collector 阶段 CPU 耗费占比下降到 7% 左右，再观察下 GC 追踪结果：显然，semi space 调大为 64M 后，scavenge 次数从近 1000 次降低到 294 次，但是这种状况下每次的 scavenge 回收耗时没有明显增加，还是在 50 ~ 60ms 之间波动，因此 3min 的 GC 追踪总的停顿时间从 48s 下降到 12s，相对应的，业务的 QPS 提升了约 10% 左右。 II. semi space 设置为 128M 进一步调大 semi space 的值为 128M 时，观察 CPU Profile 结果：此时 garbage collector 耗费下降相比上面的设置为 64M 并不是很明显，同样观察 GC 追踪结果：很明显，造成相比设置为 64M 时 GC 占比提升不大的原因是：虽然此时进一步调大了 semi space 至 128M，并且 scavenge 回收的次数从 294 次下降到 145 次，但是每次算法回收耗时近乎翻倍了，因此总收益并不明显。 III. semi space 设置为 256M 进一步将 semi space 调整为 256M 后测试，结果其实和 128M 时非常类似：相对 64M 的情况，此时 3min 内 scavenge 次数从 294 次下降到 72 次，但是相对的每次算法回收耗时波动到了 150ms 左右，因此整体性能并没有显著提升，入下图所示： IV. 小结通过以上的测试改进 semi space 的值后，可以看到从默认的 16M 设置到 64M 时，node 应用的整体 GC 性能是有显著提升的，并且反映到压测 QPS 上大约提升了 10%；但是进一步将 semi space 增大到 128M 和 256M 时，收益确并不明显，而且 semi space 本身也是作用于新生代对象快速内存分配，本身不宜设置的过大，因此这次优化最终选取对此项目最优的运行时 semi space 的值为 64M。尾声通过 GC 方面的运行时调优来提升我们的项目性能是一种大家不那么常用的方式，这也有很大一部分原因是应用运行时 GC 状态本身不直接暴露给开发者。通过上面这个真实的客户案例，我们可以看到借助于 Node.js 性能平台，实时感知 Node 应用 GC 状态以及进行对应的优化，使得不改一行代码提升项目性能变成了一件非常容易的事情。

发表了文章 2018-08-03

Node 案发现场揭秘 —— Core dump 还原线上应用异常

前言 Node.js 发展到今天，已经被越来越广泛地应用到 BFF 前后端分离、全栈开发、客户端工具等领域。然而，相对于应用层的蓬勃发展，其 Runtime 对于绝大部分前端出身的开发者来说，处于黑盒的状态，这一点并没有得到很好的改善，从而也阻碍了 Node.js 在业务中的应用和推广。笔者目前就职于阿里巴巴 AliNode 团队，在过去几年里，亲身经历过的很多线上故障，其中让开发者最头痛又最难以排查的是：内存泄漏 CPU 长期 100%（类死循环）第一点中，对于缓慢上涨最终 OOM 这种类型的内存泄漏，我们有充足的时间去抓 Heapsnapshot，进而分析堆快照来定位泄漏点。（可参见之前的文章『Node 案发现场揭秘 —— 快速定位线上内存泄漏』）而第二点，对于诸如 while 循环跳出条件失败、长正则执行导致进程假死、以及由于异常请求导致应用短时间内 OOM 的情况，往往来不及抓取 Heapsnapshot，一直没有特别好的办法进行处理。本文将介绍一种基于 core dump 来分析定位线上应用故障的方法。背景知识排查疑难杂症，无非是先想办法保存现场，然后再通过工具去分析。如何保存现场？首先要介绍下 Core Dump，它是操作系统提供的调试辅助操作，包含内存分配信息、program counter 以及堆栈指针等关键信息，对于开发者诊断和调试程序非常有帮助（有些程序错误是很难重现的）。生成 Coredump 文件有两种方式：当我们的应用意外崩溃终止时，操作系统将自动记录。这种方式一般用于 __「死后验尸」__，用于分析由雪崩触发 OOM。我们首先要使用 ulimit -c unlimited 打开内核限制，也可以选在 Node 应用启动时加上参数 --abort-on-uncaught-exception 来对出现未捕获的异常时也进行自动 Core dump。这里需要注意的是，这是一个并没有那么安全的操作：线上一般会 pm2 等具备自动重启功能的守护工具进行进程守护，这意味着如果我们的程序在某些情况下频繁 crash 和重启，那么会生成大量的 Coredump 文件，甚至可能会将服务器磁盘写满。所以开启这个选项后，__请务必记得对服务器磁盘进行监控和告警。__ 手动调用 gcore <pid> 的方式来手动生成。这种方式一般用于「活体检验」__，用于 __Node.js 进程假死状态下的问题定位。拿到了问题进程的 Coredump 文件，剩下的问题就是如何去分析。如何分析？一般会借助于 mdb、gdb、lldb 等工具来诊断 crash 的原因，但这些工具都只能帮助我们回溯到 c++ 层面的堆栈信息，如下： // crash.js const article = { title: "Node.js", content: "Hello, Node.js" }; setTimeout(() => { console.log(article.b.c); }, 1000); 当我们开启 ulimit 参数并执行 node --abort-on-uncaught-exception crash.js 后，可以看到当前目录会生成一份 core.<pid> 格式的文件（mac 下通常会在 /cores/ 目录下），接着我们尝试使用 lldb 进行尝试分析： $ lldb node -c core.<pid> 命令行提示 Core file xxx was loaded. 时，表示已经加载成功，接着我们执行 bt ，来回溯下 crash 时刻的栈信息，可以看到如下图所示：熟悉 Node.js 源代码的同学会发现 node::Start -> uv_run -> uv__run_timers 确实是从启动到进入 libuv 的地方，并且这里应该是执行了一个 js 层的 timer 导致的奔溃，这些分析和我们的问题代码确实是符合的，然而考虑到线上真实代码的复杂度，显然单纯靠 c++ 的栈信息，我们并不能看到是哪里的 js 代码触发了进程奔溃。幸好我们有 llnode，它实际上是 lldb 的一个插件，它借助于 lldb 暴露出来的 api，经过转换后能够还原 js 栈和 v8 对象，sourcemap 的既视感有没有？ $ # 安装 llnode $ npm install llnode -g $ $ # 分析 $ llnode node -c core.<pid> 然后执行 v8 bt 进行回溯，结果如下图所示： Cool~ js 的栈信息也能看到了，借助于这样更加完整的信息，我们就可以很快的定位到问题函数了。看到这里，似乎我们今天的话题就可以结束了，毕竟借助 llnode + Coredump，我们已经完美解决了之前提到的疑难杂症。但在实际使用中，__纯客户端的 llnode 还有一些问题__：安装配置麻烦 llnode 依赖 lldb 版本，部分 Coredump 文件在 lldb-3.x/4.x 下无法获取到正确的栈信息。 llnode 插件本身是 addon，本地安装编译需要高版本 gcc（支持 c++11）和 python 环境的支持。还原 utf8 编码的中文存在问题，导致一些中文字符串会乱码，且被异常截断导致字符串大小出错影响故障排查。分析方式不够自动化和智能默认线程未必是 JS 线程，这种情况下需要手动挨个去查找 JS 线程。命令行下 js 栈和 c++ 栈加上一些 unknown stub 挤在一块很是考验眼力。 Coredump 分析服务 Coredump 分析服务是 Node.js 性能平台（Alinode）提供的一项 __免费服务__，我们基于开源的 llnode 进行了二次开发和深度定制，解决了上述问题，可以降低开发者的使用门槛，并更智能的去辅助分析定位线上故障。下面将使用两个真实的故障案例，来给大家展现下。使用准备首先简单介绍下如何将 Coredump 文件以及可执行 node 文件上传分析。访问控制台主页，打开任意一个应用界面的文件选项。（如果你没有创建过应用，可以先按照创建应用流程创建一个新应用。）文件列表默认展示的是原来的 Heapsnapshot、CPU Profile 和 GC Trace 等性能分析文件，现在新增了 Coredump 分析文件列表，只需要将鼠标移动到左边 Tab 栏目的文件按钮上，可以看到新增内容：选择 Coredump 文件 __即可进入 Coredump 文件列表，点击上图中的 __上传文件选项，即可在弹出框中按照提示将对应的 Coredump 文件和 node 可执行文件上传至服务器了。这里需要注意的是，请将 Coredump 文件以 .core 结尾重命名，Node 可执行文件以 .node 结尾重命名，推荐的命名方式为 <os info>-<alinode/node>-<version>.node__，方便以后回顾，比如 centos7-alinode-v4.2.2.node 这种。最后 Coredump 文件和 node 可执行文件之间必须是 __一一对应的关系。这里一一对应指的是：这份 Coredump 文件必须是由这个 Node 可执行文件启动的进程生成的，如果这两者没有一一对应，分析结果往往是无效信息。 CPU 长期 100%（类死循环）样例使用 Egg.js 搭建，首先来看这样的一段 Egg Controller 代码： 'use strict'; const Controller = require('egg').Controller; class RegexpController extends Controller { async long() { const { ctx } = this; let str = ' ' + ' 早餐后自由活动，于指定时间集合自行办理退房手续。'; str += ' ' + ' ' + ' '; str += ' ' + ' ' + ' ' + ' '; str += ' '; str += ' ' + ' ' + ' 根据船班时间，自行前往暹粒机场，返回中国。 '; str += '如需送机服务，需增加280/每单。 '; const r = str.replace(/(^(\s*?<br[\s\/]*?>\*?)+|(\s*?<br[\s\/]*?>\s*?)+?$)/igm, ''); ctx.body = r; } } module.exports = RegexpController; 在 Node.js 应用中，正则匹配是一个相当常见的操作，并且正则表达式匹配的字符串往往来自于用户和其它内部接口。这意味着匹配字符串本身不是那么可控的，因此如果一个异常的输入触发了__正则表达式灾难性的回溯__，会导致执行时间要耗费几年甚至几十年，显然不管是那种情况，单主工作线程的模型会导致我们的 Node.js 应用处于假死状态，即进程依旧存活，但是却不再处理新的请求。上述这段代码中，模拟了这样的一种回溯状态，当我们访问到这个 Controller 时，会发现 Node.js 服务器会立即卡住，此时使用 gcore 生成一份当前进程的 Coredump 文件，按照上一小节中的方式，我们将生成的 Coredump 文件和对应的 node 可执行文件重命名后上传，耐心等待上传成功后，可以看到如下界面：点击分析按钮，即可开始分析，等待分析完成后如下图所示: 在 llnode 中，实际上默认的 thread 1 并不一定是主线程，这里我们将包含 JS 栈信息的线程过滤出来，并且标红置顶方便使用，点开这里的 Main JS Thread 后，可以看到当前的 frame 详情：此时很容易就能看到，进程当前在执行一个 replace 操作，并且正则表达式的具体内容和执行这个 replace 正则操作的函数位置也很清楚。甚至这里省略展示的正则匹配字符串，我们想要看到全貌的话也非常简单：鼠标移动到 " ..." 字符串上并点击一下，就可展开更多内容：可以看到，这里的字符串内容和我们代码中模拟的触发长回溯的字符串一模一样。另外这种 CPU 长期 100% 的问题，我们也提供了另外相对轻量的方式来解决，详情参见 Node.js 性能平台支持死循环和正则攻击定位。堆内存短时间内雪崩短时间内堆内存雪崩也是一类相对难以排查的问题，因为内存告警一般有时间差，一些情况下等我们收到堆内存告警时，进程其实已经 OOM 并重启了，根本来不及抓堆快照，可以看下面的一个例子： 'use strict'; const Controller = require('egg').Controller; const fs = require('fs'); const path = require('path'); const util = require('util'); const readFile = util.promisify(fs.readFile); class DatabaseError extends Error { constructor(message, stack, sql) { super(); this.name = 'SequelizeDatabaseError'; this.message = message; this.stack = stack; this.sql = sql; } } class MemoryController extends Controller { async oom() { const { ctx } = this; let bigErrorMessage = await readFile(path.join(__dirname, 'resource/error.txt')); bigErrorMessage = bigErrorMessage.toString(); const error = new DatabaseError(bigErrorMessage, bigErrorMessage, bigErrorMessage); ctx.logger.error(error); ctx.body = { ok: false }; } } module.exports = MemoryController; 这个例子也是来源于一个真实的线上故障，当我们使用 egg-logger 输出日志的时候，很多时候会像例子中一样，不去对属性加以限制直接输出，而在 egg-loger 中，当我们传入的第一个参数是 Error 的实例时，会去调用 Node.js 核心库 util 中的 inspect 方法进行格式化。问题就在这里，如果 error 对象上面有一些属性包含了很大的字符串，做 inspect 的时候就会溢出触发 OOM，这里正是在 resource/error.txt 中填充了一个大字符串模拟了这种情况。如果此时我们按照第二节中的说明已经打开了 ulimit 参数限制，那么堆内存迅速雪崩时，系统会自动生成一份 Coredump 文件，同样我们把这份 Coredump 文件和对应的 node 可执行文件上传到性能平台，并点击分析按钮，等待分析完成后点开标红的 JS 主线程，可以看到如下信息：圈起来的 JS 调用栈和我们之前提到的过程完全一致，更多的，我们可以看下产生问题的字符串大小，将鼠标悬浮到字符串上可以看到字符串大小：这里正是这个 186M 的大字符串 inspect 时导致了 OOM。而在那个真实的线上故障中，实际上是拼接的 sql 语句非常大，大小约为 120M，因此首先导致数据库操作失败，接着数据库操作失败后输出的 DatabaseError 对象实例上则原封不动地将问题 sql 语句设置到属性上，从而导致了 ctx.logger.error(error) 时堆内存的雪崩。一些感想笔者从 14 年开始投入到 Node.js 相关方面的开发，写过业务，做过基础架构，到现在致力于更底层的保障。虽然不算是国内最早一批接触到 Node.js 的开发者，但这一路走来，也是看到了这样一门年轻的技术伴随着不断质疑的发展历程。不够稳定、玩具、只能拿来写写脚本工具、不能做大型项目是常见的社区里的一些声音。在我看来，对于开发者自身而言：首先，我们需要去避免拿着锤子找钉子这种自我局限的想法，毕竟任何技术都有其适用和不适用的场景。其次，Node.js 的社区繁荣和生态蓬勃发展已经证明了她作为一门服务端技术的魅力所在，而且在底层的性能稳定性和故障排查这一层面上，现在已经有了很多的办法去完成我们以前很难做到的一些事情，所以我们对于这门技术本身应该有更多的信心。在这历程中，朴灵老师组建了 Alinode 团队，专注为阿里数以千计的 Node 应用保驾护航，专治 Node 的各种疑难杂症。目前我们只是从 0 到 10，未来还有很多很多空白等着我们去填补，如果你有志于此，快来私信勾搭加入我们吧！参考资料 https://en.wikipedia.org/wiki/Core_dump https://github.com/nodejs/llnode https://yq.aliyun.com/articles/610395

发表了文章 2018-05-02

快速定位线上 Node.js 内存泄漏问题

背景目前容器化和微服务是服务端开发的一个潮流和趋势，然而在这种微服务的架构下，我们在实际的企业开发中会遇到一些困境：趋向于越来越稳定的服务端 API 和多样化高灵活性的用户诉求间存在天然的矛盾。更通俗地描述一些实际开发的场景：Android、IOS、PC 和 M 站对于同一个性质的接口需求的字段不一致，导致的前端开发和服务端开发间经常会因为增减字段产生的大量的沟通开销。为了解决这样的一个困境，一些公司采取了在传统的前端和后端之间加入一层 BFF 层，进而达到谁使用谁开发维护的目的。很显然，对于前端比较熟悉的 Node.js 是这个 BFF 层实现的一个比较理想的语言。但是这样做其实又引入了一些新的问题（典型的为了解决一个问题又引入了一个新的问题），相对于传统的比较成熟的 Java 语言来说，Node.js 的 runtime 对于绝大部分开发者来说是一个黑盒，没有对应的生态链工具来保障这个由 BFF 层运行的稳定————比如线上出现内存泄漏导致进程间歇性 OOM 了，我们应该怎么去处理定位。这篇文章旨在这个大背景下对 Node.js 的开发中遇到内存泄漏问题做一些展开和探讨。堆快照浅探获取堆快照想要分析定位内存泄漏问题，首先我们要去获取 Node.js 进程在发生泄漏时的堆上各个对象和它们间的引用关系，这个保存了堆上各个对象以及其引用关系的文件就是堆快照。V8 引擎提供了一个接口可以让我们很方便地实时获取到堆快照，下面我们介绍三种不同的方法来获取。 heapdump 首先可以执行如下命令安装 heapdump 模块: npm install heapdump 此模块需要在代码中引入： const heapdump = require('heapdump'); heapdump 模块提供了两种方式来获取进程当前的堆快照，第一种是在代码中通过自定义逻辑（可以是定时器定是获取，或者长连接开关热启动），下面是一个例子： 'use strict'; const heapdump = require('heapdump'); const path = require('path'); setInterval(function() { let filename = Date.now() + '.heapsnapshot'; heapdump.writeSnapshot(path.join(__dirname, filename)); }, 30 * 1000); 这里每隔 30s 输出一个堆快照到到当前目前下。第二种是启动引入了 heapdump 模块的 Node.js 进程后，通过 usr2 这个信号量来触发堆快照： kill -USR2 <需要获取堆快照的 Node.js 进程 PID> 这种办法的好处是不需要在代码中植入相关逻辑，而仅在需要的时候 ssh 到服务器上通过信号量获取到堆快照。 v8-profiler 首先可以执行如下命令安装 heapdump 模块: npm install v8-profiler v8-profiler 提供了 transform 流的形式输出堆快照，对于一些比较大的堆快照文件能更好的进行生成处理： 'use strict'; const v8Profiler = require('v8-profiler-node8'); const snapshot = v8Profiler.takeSnapshot(); // 获取堆快照数据流 const transform = snapshot.export(); // 流式处理堆快照 transform.on('data', data => console.log(data)); // 数据处理完毕后删除 transform.on('finish', snapshot.delete.bind(snapshot)); v8-profiler 在 Node.js v6.x 之前的版本中通过 node-pre-gyp 可以直接下载到对应系统的 binary，无需进行本地编译，对于一些非 mac 类的开发环境还是比较友好的。 Node.js 性能平台前面给大家介绍的方法都需要安装 npm 模块，并且需要在代码中埋入对应的热操作逻辑，Node.js 性能平台目前将堆快照的获取整合进了 runtime 中，只要应用接入平台后，不需要改动业务代码即可在线获取到进程的堆快照以备分析：如果所示，选中需要操作的进程后，点击堆快照按钮，即可生成堆快照，点击导航栏左侧的文件选项，即可看到刚才生成的堆快照：此时点击转储至云端后，即可随时随地下载分析了。堆快照内容解析字段含义用任意的文档阅读工具打开上一节中获取的堆快照后，可以看到它里面的内容本质上是一个大 json： { snapshot: {}, nodes: [], edges: [], strings: [] } 这里面很好猜测的是 nodes 和 edges，显然 nodes 数组中保存的一定是内存关系中每一个节点的信息，edges 数组保存的是内存关系图中每一个节点间的联系。那么 snapshot 保存的其实是描述每一个 node 和 edge 的描述信息，我们展开 snapshot 节点后，可以看到它里面只有一个 meta 节点，继续展开 meta 节点，就可以看到 node 和 edge 的描述信息了： meta.node_fields: 数组，数组的长度就是一个 node 实际需要 nodes 数组中对应长度的数字来表示，这里显然可以看到 nodes 数组中每 6 位表示一个 node。 meta.node_types: 数组，其中的元素表示一个 node 每一位的含义，这里可以看到 6 位中的第一位表示节点类型，并且节点类型也是在有限的一个数组中。 meta.edge_fields: 数组，数组的长度就是一个 edge 实际需要 edges 数组中对应长度的数字来表示，这里显然可以看到 edges 数组中每 3 位表示一条边。 meta.node_types: 数组，其中的元素表示一个 edge 每一位的含义，这里可以看到 3 位中的第一位表示边的类型，并且边的类型也是在有限的一个数组中。最后是 strings 数组，它的含义比较简单，其内部实际上保存的是 node 和 edge 的名称。整体的关系图如下所示：节点和边通过上面的信息，我们可以获取到内存关系图所需的每一个节点和每一条边的描述，但是依旧缺失节点和边之间的关系来补完全图。我们可以注意到，上面描述 node 信息的 meta.node_fields 中有一项叫做 edge_count，这个显然描述的是此节点下属边的条数，而且 edges 数组中的边是按照顺序排列的，那么依据这些信息，我们可以构建如下的一个关系图；并且描述边信息的 meta.edge_fields 中又有一项叫做 to_node，它指的是这条边指向的 node，那么结合之前的内容，可以比较完整地构建出真正的内存关系图了。定位内存泄漏根据上一节的内容，我们可以获得类似如下所示的内存关系图：我们可以思考这样的一个问题，假如节点 5 是内存泄漏的地方，它累积了大量的内存没有被正常的释放掉。此时我们如果释放掉它的父节点 3，那么从根节点出发依旧可以 1->2->4->5 的路径到达 5，也就是单独释放掉节点 3，并不能断开节点 5 的引用；同理可得节点 4。在这个例子中，只有当我们断开节点 2 的引用时，才能释放掉节点 5，换句话说，从根节点 1 出发到节点 5，所有的路径都会经过节点 2，这就意味着节点 2 才是节点 5 的直接支配者。这里就引入了支配树的概念，它对于分析内存泄漏非常有帮助。我们将上图的内存引用关系图转化为支配树，如下图所示：此时从支配树的叶节点 8 开始向上到根节点计算 retained size，每一个节点的 retained size = 节点自身的 self size + 子节点的 retained size，最后就可以看到内存累积在哪一处，我们可以认为这些内存累积的节点有可能正是没有正常被回收从而引发内存泄漏的地方。获取到这些可疑的泄漏点后，再次还原到内存关系图中定位到对应的代码逻辑片段，那么最终的内存泄漏确认还是要回到这些代码逻辑片段，看它们是否真的会产生一些预期之外的无法释放掉的内存。实战下面有两个真实线上内存泄漏的案例，在线获取到堆快照后，经过上述的定位分析流程找到内存累积的可疑泄漏点，还原后最终定位到了泄漏代码，感兴趣的同学可以看下详细的内容：事件侦听器泄漏模块热更新泄漏参考文档： heapdump v8-profiler devtoolx 故障诊断-内存泄漏

发表了文章 2018-04-02

Co、递归调用引发的内存泄漏

前言我们知道，同步的递归写法，如果在退出递归条件失效时，会快速因为栈溢出导致进程挂掉。而在某些场景下，我们会采用异步的递归写法来规避这个问题： async function recursive() { if( active ) return; // do something await recursive(); } 关键字 await 后面的函数调用可能会跨越多个 event loop，这样的写法下不会出现栈溢出的错误。然而这种写法其实也不是万无一失的，我们来看下面这个生产故障案例。发现问题客户接入 Node.js 性能平台后，通过监控经常出现内存增长导致的 OOM，于是客户加上了一条告警规则：@heap_used / @heap_limit > 0.5，目的是在堆较小但是发生泄漏时能正常输出 heapsnapshot 文件用于分析。经过授权，我们得以进入客户的项目，看到获取到的 heapsnapshot 文件，与此同时，可以通过进程趋势图看到内存飙高引发的一些“并发症”，比如 GC 耗时变久，降低了进程的处理效率：定位问题借助这次顺利生成的堆快照（heapsnapshot）文件，大致能看出内存泄漏的地方在哪里，但想要完全找出来，还有点难度。堆快照分析第一个信息，内存泄漏报表：可以看到，将近 1 个G的文件，当看到 (context) 这个字样的时候，表明的是它并不是一个普通的对象，而是函数执行期间所产生的上下文对象，比如闭包。函数执行完了，这个上下文对象并不一定就消失了。另外这个上下文对象跟 co 模块有关，这说明 co 应该是调度了一个长时期执行的 Generator。否则这类上下文对象会随着执行结束，进入 GC 回收。但这点信息完全无法得出任何结论。继续看。尝试根据 @22621725 查看对象内容，尝试根据 @22621725 查看到 GC root 的引用。无果。接下来比较有效的信息在对象簇视图上：可以看到从 @22621725 开始，一个 context 引用又一个 context，中间穿插一个 Promise。熟悉 co 的同学会知道 co 会将非 Promise 的调用转化为一个 Promise，这个地方的 Promise 意味着一个新的 Generator 的调用。这里的引用关系非常长，笔者展开 20 层之后，Percent 的占比还没有降低万分之一。这里线索中断了。下一个有用的信息是类视图：这个图里有不太常见的东西冒出来：scheduleUpdatingTask。这个堆快照中有 390,285 个 scheduleUpdatingTask 对象，点击该类，查看详情：这个类在文件 function /home/xxx/app/schedule/updateDeviceInfo.js() / updateDeviceInfo.js 中。目前能提供的线索就仅限这些了，接下来进入代码分析的阶段。代码分析经过客户授权，拿到了相关的代码，找到 app/schedule/updateDeviceInfo.js 文件中的 scheduleUpdatingTask // 执行业务，成功之后稍作等待，继续 // 如果拿锁失败了，停止 const scheduleUpdatingTask = function* (ctx) { if (!taskActive) return; try { yield doSomething(ctx); } catch (e) { // 需要捕获业务异常，即使挂了，下一次schedule也能正常跑 ctx.logger.error(e); } yield scheduleUpdatingTask(ctx); }; 在整个项目中，唯一能找到对 scheduleUpdatingTask 反复调用的，就只有它自身对自身的调用，也就是通常所说的递归调用。当然，完全说是递归调用也不是很符合实际情况。因为如果真的是递归调用的话，栈首先就溢出了。栈没有溢出的原因在于 Co/Generator 体系中，yield 关键字的前后执行实际上是跨多个 eventloop 过程的。虽然没有栈溢出，但 Generator 执行之后所附属的 context 对象要在整个 generator 执行完成之后才会销毁。因此这个地方的递归就导致 context 引用 context 的过程，于是内存就无法得到回收。在这段代码中，很明显的是 if (!taskActive) return; 这个终止条件失效了。根据这段代码反推之前的表现，完全符合现象。为了确认这个问题，笔者写了一段代码来尝试重现该问题： const co = require('co'); function sleep(ms) { return new Promise((resolve) => { setTimeout(() => { resolve(); }, ms); }); } function* task() { yield sleep(2); console.log(process.memoryUsage()); yield task(); } co(function* () { yield task(); }); 执行这段代码后，应用程序不会立即崩溃，而是内存会逐渐增长，跟出问题的客户项目表现得一摸一样。当然我们猜想，是不是 async functions 不会导致这个问题： function sleep(ms) { return new Promise((resolve) => { setTimeout(() => { resolve(); }, ms); }); } async function task() { await sleep(2); console.log(process.memoryUsage()); await task(); } task(); 答案是内存仍然会持续增长。解决问题虽然这次的 heapsnapshot 在 Node.js 性能平台中的分析不是很顺畅，但我们还是找到了问题点。既然找到原因了，那么我们继续看一下该如何解决这个问题。从上面的例子可以看出，在 co 或者 async functions 中使用递归调用，会导致内存回收被延迟，这种延迟会导致内存堆积，引起内存压力。这是不是意味着在这种场景下不能使用递归了。答案当然不是。但我们需要对应用程序评估，这个递归会引起多长的引用链路。在本文这个例子中，在退出条件失效的情况下，相当于就是无限递归。那有没有一种继续执行，但不引起上下文引用链路太长的方案？答案是有： async function task() { while (true) { await sleep(2); console.log(process.memoryUsage()); } } 上文通过将递归调用换成 while (true) 循环后，就不再有上下文引用链路的问题。由于内部有 await 会引起 eventloop 的调度，所以 while (true) 并不会阻塞主线程。题外话普通函数的尾递归优化当前都还不是很好，更何况 Generator/Async Functions。

发表了文章 2018-03-28

Node.js 性能平台新功能——模块仓库

写在前面受限于国内的网络环境，官方的 npm 仓库安装速度不尽人意，在此基础上，阿里巴巴提供了 cnpm 完全镜像仓库来满足国内的开发者安装 npm 包的需求。并且 cnpm 的镜像仓库源代码是开源的，所以许多有私有模块发布安装需求企业纷纷使用开源的 cnpm 来搭建企业自己的私有镜像仓库。模块仓库 Node.js 性能平台同样基于 cnpm 开发，向广大开发者免费提供企业私有仓库：模块仓库，目的是简化 Node.js 开发上的一些环境部署工作，以一套底层性能监控 + 上层应用框架（推荐 Egg.js，一起搭配味更佳）+ 模块仓库作为解决方案，让开发者能更聚焦于业务本身。相比企业使用开源的 cnpm 搭建的私有仓库，我们提供的模块仓库具有的一些优势如下：节省企业运营开支：视企业开发规模搭建私有仓库需要长期维护 1 台以上的物理机/ECS，以及对应的存储空间覆盖场景更广：如果存在一些企业外部的合作伙伴共享某些私有模块，自行搭建的私有仓库无法满足精确的权限控制：cnpm 私有仓库无法精确到每一个 scope 的用户下载/发布权限粒度可以看到，Node.js 性能平台推出的模块仓库，在完全覆盖 cnpm 私有仓库功能的基础上，提供了一套多用户隔离 + 精确权限控制的模式，能够覆盖企业开发中面临的多种场景，最关键的是这一切功能目前是免费提供的。下面我们以一个简单的例子来体验下使用 Node.js 性能平台提供的模块仓库功能来发布一个私有包的过程，有兴趣的小伙伴可以跟着尝试一番尝试一番创建 Registry 第一次访问模块仓库主页的话，需要先进行 registry 的创建，这里的 registry 即你的私有仓库，此时可以点击页面右上角的创建新 registry 来创建一个私有模块仓库，如下图所示：登入 Registry Registry 创建后，将会在页面上看到你创建的私有仓库的地址，如下图所示：使用图中提示的 npm/cnpm 命令将 npm/cnpm 客户端仓库指向这个私有模块仓库，再执行登录操作即可，其中 npm/cnpm 客户端 login 命令所需要的账户信息在我的信息可以看到，如下图所示：创建 scope 接下来我们就需要在我们创建的这个私有仓库下按照业务/部门/功能等你任意希望的区分来创建 scope，点击模块仓库主页右上角的创建新 scope 来执行创建，如下图所示: 创建 scope 成功后，我们就可以将包名对应这个 scope 的私有模块发布到这个 scope 里面，例如这里创建了名字为 @cloud 的 scope，那么我们可以执行 npm publish 命令将 @cloud/quickstart 这样名称的包到这个 scope 下。更多功能上面的尝试只是一个最简单的单人使用模块仓库的例子，在实际的企业开发中，必然是存在多人合作开发维护私有模块的使用场景，因此 Node.js 性能平台提供的模块仓库还提供了完整的多人协作开发模式下的使用，这一块进阶教程可以参见完整文档: 模块仓库使用指南。目前模块仓库功能正在火热公测中，欢迎广大开发者将自己的私有模块迁移过来，使用中遇到的任何问题可以加钉钉群咨询，钉钉群号：11794270。

hyj1991_个人页

个人介绍

擅长的技术

逆工程 JS 对象 (一): 浅谈 V8 对象布局

Node.js 应用故障排查手册 —— 雪崩型内存泄漏问题

Node.js 应用故障排查手册 —— 类死循环导致进程阻塞

Node.js 应用故障排查手册 —— 综合性 GC 问题和优化

Node.js 应用故障排查手册 —— 冗余配置传递引发的内存溢出

Node.js 应用故障排查手册 —— 利用 CPU 分析调优吞吐量

Node.js 应用故障排查手册 —— Node.js 性能平台使用指南

Node.js 应用故障排查手册 —— 正确打开 Chrome devtools

Node.js 应用故障排查手册 —— 大纲与常规问题指标简介

如何进行 GC 调优提升 Node 应用性能

Node 案发现场揭秘 —— Core dump 还原线上应用异常

快速定位线上 Node.js 内存泄漏问题

Co、递归调用引发的内存泄漏

Node.js 性能平台新功能——模块仓库

逆工程 JS 对象 (一): 浅谈 V8 对象布局

Node.js 应用故障排查手册 —— 雪崩型内存泄漏问题

Node.js 应用故障排查手册 —— 类死循环导致进程阻塞

Node.js 应用故障排查手册 —— 综合性 GC 问题和优化

Node.js 应用故障排查手册 —— 冗余配置传递引发的内存溢出

Node.js 应用故障排查手册 —— 利用 CPU 分析调优吞吐量

Node.js 应用故障排查手册 —— Node.js 性能平台使用指南

Node.js 应用故障排查手册 —— 正确打开 Chrome devtools

Node.js 应用故障排查手册 —— 大纲与常规问题指标简介

如何进行 GC 调优提升 Node 应用性能

Node 案发现场揭秘 —— Core dump 还原线上应用异常

快速定位线上 Node.js 内存泄漏问题

Co、递归调用引发的内存泄漏

Node.js 性能平台新功能——模块仓库