Skip to content

Commit

Permalink
update
Browse files Browse the repository at this point in the history
  • Loading branch information
nswbmw committed Mar 20, 2018
1 parent 8308e14 commit 3d160c9
Show file tree
Hide file tree
Showing 15 changed files with 52 additions and 53 deletions.
25 changes: 12 additions & 13 deletions 1.1 perf + FlameGraph.md
Original file line number Diff line number Diff line change
Expand Up @@ -121,22 +121,21 @@ $ ~/FlameGraph/stackcollapse-perf.pl --kernel < ~/perf.stacks | ~/FlameGraph/fla
- -g 启用 call-graph 记录。
- -- sleep 30 指定记录 30s。

- sudo chown root /tmp/perf-3009.map
- sudo chown root /tmp/perf-3009.map,将 map 文件更改为 root 权限,否则会报如下错误:

- 将 map 文件更改为 root 权限,否则会报如下错误:
> File /tmp/perf-PID.map not owned by current user or root, ignoring it (use -f to override).
> Failed to open /tmp/perf-PID.map, continuing without symbols
- perf record 会将记录的信息保存到当前执行目录的 perf.data 文件,使用 perf script 读取 perf.data 的 trace 信息写入 perf.stacks。
- perf record 会将记录的信息保存到当前执行目录的 perf.data 文件中,然后使用 perf script 读取 perf.data 的 trace 信息写入 perf.stacks。

- --color=js 指定生成针对 js 配色的 svg,即:
- --color=js 指定生成针对 JavaScript 配色的 svg,即:

- green:JavaScript。
- blue:Builtin。
- yellow:C++。
- red:System(native user-level, and kernel)。

ab 压测用了 30s 左右,浏览器打开 flamegraph.svg,截取关键的部分如下图所示:
ab 压测用了 30s 左右,用浏览器打开 flamegraph.svg,截取关键的部分如下图所示:
![](./assets/1.1.1.png)

## 1.1.2 理解火焰图
Expand All @@ -145,13 +144,13 @@ ab 压测用了 30s 左右,浏览器打开 flamegraph.svg,截取关键的部

- 每一个小块代表了一个函数在栈中的位置(即一个栈帧)。
- Y 轴代表栈的深度(栈上的帧数),顶端的小块显示了占据 CPU 的函数。每个小块的下面是它的祖先(即父函数)。
- X 轴代表总的样例群体。它不像绝大多数图表那样从左到右表示时间的流逝,其左右顺序没有特殊含义,仅仅是按照字母表的顺序排列
- 小块的宽度表示 CPU 的使用时间,或者说相对于父函数而言使用 CPU 的比率(基于所有样例),越宽则代表占用 CPU 的时间越长,或者使用 CPU 很频繁。
- X 轴代表总的样例群体。它不像绝大多数图表那样从左到右表示时间的流逝,其左右顺序没有特殊含义,仅仅按照字母表的顺序排列
- 小块的宽度代表 CPU 的使用时间,或者说相对于父函数而言使用 CPU 的比例(基于所有样例),越宽则代表占用 CPU 的时间越长,或者使用 CPU 很频繁。
- 如果采取多线程并发运行取样,则取样数量会超过运行时间。

**从上图可以看出**:最上面的绿色小块(即 JavaScript 代码)指向 test/app.js 第 18 行,即 `GET /auth` 这个路由。再往上看,黄色的小块(即 C++ 代码) node::crypto::PBKDF2 占用了大量的 CPU 时间。

**解决方法**:将同步改为异步,即将 crypto.pbkdf2Sync 改为 crypto.pbkdf2修改如下:
**解决方法**:将同步改为异步,即将 crypto.pbkdf2Sync 改为 crypto.pbkdf2修改如下:

```js
app.route({ method: 'GET', path: '/auth', async controller (ctx) {
Expand Down Expand Up @@ -182,12 +181,12 @@ app.route({ method: 'GET', path: '/auth', async controller (ctx) {

![](./assets/1.1.2.png)

**可以看出**:只有在左侧极窄的绿色小块可以看到 JavaScript 代码,红色的部分我们不关心也无法优化。那么,为什么异步比同步的 QPS 要高呢?原因是 Node.js 底层的 libuv 用了多个线程做计算任务,这里就不再深入介绍了。
**可以看出**:只有在左侧极窄的绿色小块可以看到 JavaScript 代码,红色的部分我们不关心也无法优化。那么,为什么异步比同步的 QPS 要高呢?原因是 Node.js 底层的 libuv 用了多个线程进行计算,这里就不再深入介绍了。

svg 火焰图的其他小技巧如下:

1. 单击任意一个小块可以展开,即被单击的小块宽度变宽,它的子函数也按比例变宽,方便查看。
2. 可单击 svg 右上角的 search 按钮进行搜索,被搜索的关键词会高亮显示,在有目的查找某个函数时比较有用
1. 单击任意一个小块即可展开,即被单击的小块宽度变宽,它的子函数也按比例变宽,方便查看。
2. 可单击 svg 右上角的 search 按钮进行搜索,被搜索的关键词会高亮显示,在有目的地查找某个函数时比较有用

## 1.1.3 红蓝差分火焰图

Expand Down Expand Up @@ -234,7 +233,7 @@ svg 火焰图的其他小技巧如下:

**如上缺点是**:如果一个代码执行路径完全消失了,那么在火焰图中就找不到地方来标注蓝色,我们只能看到当前的 CPU 使用情况,却不知道为什么会变成这样。

一个解决办法是:生成一个相反的差分火焰图,即基于 profile1 生成 profile1 - profile2 的差分火焰图。对应命令如下:
一种解决办法是:生成一个相反的差分火焰图,即基于 profile1 生成 profile1 - profile2 的差分火焰图。对应命令如下:

```sh
$ ./FlameGraph/difffolded.pl perf_after.folded perf_before.folded | ./FlameGraph/flamegraph.pl --negate > flamegraph_diff2.svg
Expand All @@ -245,7 +244,7 @@ $ ./FlameGraph/difffolded.pl perf_after.folded perf_before.folded | ./FlameGraph
- flamegraph_diff.svg:宽度是以修改前的 profile 文件为基准,颜色表明将要发生的情况。
- flamegraph_diff2.svg:宽度是以修改后的 profile 文件为基准,颜色表明已经发生的情况。

总之,红蓝差分火焰图可能只在代码变化不大的情况下使用时效果明显,代码变化多了效果可能就不明显了
总之,红蓝差分火焰图可能只在代码变化不大的情况下使用时效果明显,在代码变化较大的情况下使用时效果可能就不明显了

## 1.1.4 参考链接

Expand Down
14 changes: 7 additions & 7 deletions 1.2 v8-profiler.md
Original file line number Diff line number Diff line change
Expand Up @@ -77,7 +77,7 @@ $ ab -c 20 -n 2000 "http://localhost:3000/encrypt?password=123456"
}
```

这个 JSON 对象记录了函数调用栈、路径、时间戳和其他一些信息,samples 节点数组与 timestamps 节点数组中的时间戳是一一对应的,并且 samples 节点数组中的每一个值,其实对应了 head 节点的深度优先遍历 ID。这里我们不深究每个字段的含义,先来看看如何可视化这些数据。
这个 JSON 对象记录了函数调用栈、路径、时间戳和一些其他信息,samples 节点数组与 timestamps 节点数组中的时间戳是一一对应的,并且 samples 节点数组中的每一个值其实对应了 head 节点的深度优先遍历 ID。这里我们不深究每个字段的含义,先来看看如何可视化这些数据。

## 1.2.2 方法 1——Chrome DevTools

Expand All @@ -89,8 +89,8 @@ Chrome 自带了分析 CPU profile 日志的工具。打开 Chrome -> 调出开

这里我们选择 Tree (Top Down) 模式,按 Total Time 降序排列。可以看到有如下三列:

1. Self Time:函数调用所花的时间,仅包含函数本身的声明,不包含任何子函数的执行时间。
2. Total Time:函数调用所花的总时间,包含函数本身的声明及所有子函数执行时间。即:父函数的 Total Time = 父函数的 Self Time + 所有子函数的 Total Time。
1. Self Time:函数调用所耗费的时间,仅包含函数本身的声明,不包含任何子函数的执行时间。
2. Total Time:函数调用所耗费的总时间,包含函数本身的声明及所有子函数执行时间。即:父函数的 Total Time = 父函数的 Self Time + 所有子函数的 Total Time。
3. Function:函数名及路径,可展开查看子函数。

我们不断地展开,并定位到了 encryptRouter,如下图所示:
Expand All @@ -101,7 +101,7 @@ Chrome 自带了分析 CPU profile 日志的工具。打开 Chrome -> 调出开

## 1.2.3 方法 2——火焰图

我们也可以用火焰图来展示 cpuprofile 数据。首先全局安装 flamegraph 这个模块
我们也可以用火焰图来展示 cpuprofile 数据。首先全局安装 flamegraph 模块

```sh
$ npm i flamegraph -g
Expand All @@ -113,7 +113,7 @@ $ npm i flamegraph -g
$ flamegraph -t cpuprofile -f cpuprofile-xxx.cpuprofile -o cpuprofile.svg
```

浏览器打开 cpuprofile.svg,如下所示:
用浏览器打开 cpuprofile.svg,如下所示:

![](./assets/1.2.2.png)

Expand All @@ -127,15 +127,15 @@ $ flamegraph -t cpuprofile -f cpuprofile-xxx.cpuprofile -o cpuprofile.svg
- 在函数执行时长超过预期时标红展示。
- 展示当前项目中可疑的内存泄漏点。

我们以上述第 2 条功能为例,使用 v8-analytics 分析 CPU 的使用情况。
我们以上述第 2 个功能为例,使用 v8-analytics 分析 CPU 的使用情况。

首先,全局安装 v8-analytics:

```sh
$ npm i v8-analytics -g
```

使用以下命令只查看执行时间大于 200ms 的函数:
使用以下命令查看执行时间大于 200ms 的函数:

```sh
$ va timeout cpuprofile-xxx.cpuprofile 200 --only
Expand Down
12 changes: 6 additions & 6 deletions 2.1 gcore + llnode.md
Original file line number Diff line number Diff line change
Expand Up @@ -4,11 +4,11 @@

**什么是 Core?**

> 在使用半导体作为内存材料前,人类是利用线圈当作内存的材料,线圈就叫作 core ,用线圈做的内存就叫作 core memory。如今 ,半导体工业澎勃发展,已经没有人用 core memory 了,不过在许多情况下, 人们还是把记忆体叫作 core 。
> 在使用半导体作为内存材料前,人类用线圈作为内存的材料,线圈就叫作 core ,用线圈做的内存就叫作 core memory。如今,半导体工业蓬勃发展,已经没有人用 core memory 了,不过在许多情况下,人们还是把记忆体叫作 core 。
**什么是 Core Dump?**

> 当程序运行的过程中异常终止或崩溃,操作系统会将程序当时的内存状态记录下来,保存在一个文件中,这种行为就叫做 Core Dump(中文有的翻译成 “核心转储”)。我们可以认为 Core Dump 是 “内存快照”,但实际上,除了内存信息之外,还有些关键的程序运行状态也会同时 dump 下来,例如寄存器信息(包括程序指针、栈指针等)、内存管理信息、其他处理器和操作系统状态和信息。Core Dump 对于编程人员诊断和调试程序是非常有帮助的,因为对于有些程序错误是很难重现的,例如指针异常,而 Core Dump 文件可以再现程序出错时的情景。
> 当程序运行的过程中异常终止或崩溃,操作系统会将程序当时的内存状态记录下来,保存在一个文件中,这种行为就叫作 Core Dump(中文翻译成 “核心转储”)。我们可以认为 Core Dump 是 “内存快照”,但实际上,除了内存信息之外,还有些关键的程序运行状态也会同时 dump 下来,例如寄存器信息(包括程序指针、栈指针等)、内存管理信息、其他处理器和操作系统状态和信息。Core Dump 对于编程人员诊断和调试程序是非常有帮助的,因为有些程序中的错误是很难重现的,例如指针异常,而 Core Dump 文件可以再现程序出错时的情景。
**测试环境**

Expand All @@ -25,13 +25,13 @@ Linux nswbmw-VirtualBox 4.13.0-36-generic #40~16.04.1-Ubuntu SMP Fri Feb 16 23:2
$ ulimit -c
```

查看允许 Core Dump 生成的文件的大小,如果是 0 则表示关闭了 Core Dump。使用以下命令开启 Core Dump 功能,并且不限制 Core Dump 生成的文件大小:
查看允许 Core Dump 生成的文件的大小,如果是 0 则表示关闭了 Core Dump。使用以下命令开启 Core Dump,并且不限制 Core Dump 生成的文件大小:

```sh
$ ulimit -c unlimited
```

以上命令只针对当前终端环境有效,如果想永久生效,需要修改 /etc/security/limits.conf 文件,如下:
以上命令只在当前终端环境下有效,如果想永久生效,就需要修改 /etc/security/limits.conf 文件,如下:

![](./assets/2.1.1.jpg)

Expand All @@ -43,7 +43,7 @@ $ ulimit -c unlimited
$ gcore [-o filename] pid
```

在 Core Dump 时,默认会在执行 gcore 命令的目录生成 core.\<PID\> 的文件
在 Core Dump 时,默认会在执行 gcore 命令的目录生成 core.\<PID\> 文件

## 2.1.3 llnode

Expand Down Expand Up @@ -273,7 +273,7 @@ Core file '/home/nswbmw/test/./core' (x86_64) was loaded.

## 2.1.7 总结

我们的测试代码很简单,没有引用任何第三方模块,如果项目较大且引用的模块较多,则 `v8 findjsobjects` 的结果将难以甄别,这个时候可以多次使用 gcore 进行 Core Dump,对比发现增长的对象,再进行诊断。
我们的测试代码很简单,没有引用任何第三方模块,如果项目较大且引用的模块较多,则 `v8 findjsobjects` 的结果将难以甄别,这时可以多次使用 gcore 进行 Core Dump,对比发现增长的对象,再进行诊断。

## 2.1.8 参考链接

Expand Down
16 changes: 8 additions & 8 deletions 2.2 heapdump.md
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
## 2.2.1 使用 heapdump

[heapdump](https://github.com/bnoordhuis/node-heapdump) 是一个 dump V8 堆信息的工具。[v8-profiler](https://github.com/node-inspector/v8-profiler) 也包含了这个功能,这两个工具的原理都是一致的,都是 v8::Isolate::GetCurrent()->GetHeapProfiler()->TakeHeapSnapshot(title, control),但是 heapdump 的使用简单些。下面我们以 heapdump 为例讲解如何分析 Node.js 的内存泄漏。

## 2.2.1 使用 heapdump

这里以一段经典的内存泄漏代码作为测试代码:

**app.js**
Expand All @@ -28,7 +28,7 @@ setInterval(function testMemoryLeak() {
}, 1000)
```

为什么这段程序会发生内存泄漏呢?首先我们要明白闭包的原理:**同一个函数内部的闭包作用域只有一个,所有闭包共享。在执行函数的时候,如果遇到闭包,则会创建闭包作用域的内存空间,将该闭包所用到的局部变量添加进去,然后再遇到闭包,会在之前创建好的作用域空间添加此闭包会用到而前闭包没用到的变量。函数结束时,清除没有被闭包作用域引用的变量**
为什么这段程序会发生内存泄漏呢?首先我们要明白闭包的原理:**同一个函数内部的闭包作用域只有一个,所有闭包共享。在执行函数的时候,如果遇到闭包,则会创建闭包作用域的内存空间,将该闭包所用到的局部变量添加进去,然后再遇到闭包时,会在之前创建好的作用域空间添加此闭包会用到而前闭包没用到的变量。函数结束时,会清除没有被闭包作用域引用的变量**

**这段代码内存泄露原因是**:在 testMemoryLeak 函数内有两个闭包:unused 和 leakMethod。unused 这个闭包引用了父作用域中的 originLeakObject 变量,如果没有后面的 leakMethod,则会在函数结束后被清除,闭包作用域也跟着被清除了。因为后面的 leakObject 是全局变量,即 leakMethod 是全局变量,它引用的闭包作用域(包含了 unused 所引用的 originLeakObject)不会释放。而随着 testMemoryLeak 不断的调用,originLeakObject 指向前一次的 leakObject,下次的 leakObject.leakMethod 又会引用之前的 originLeakObject,从而形成一个闭包引用链,而 leakStr 是一个大字符串,得不到释放,从而造成了内存泄漏。

Expand Down Expand Up @@ -74,15 +74,15 @@ heapdump-100438986.797085.heapsnapshot
4. Shallow Size:对象自身的大小,不包括它引用的对象。
5. Retained Size:对象自身的大小和它引用的对象的大小,即该对象被 GC 之后所能回收的内存大小。

**小提示**: 一个对象的 Retained Size = 该对象的 Shallow Size + 该对象可直接或间接引用到的对象的 Shallow Size 之和。Shallow Size == Retained Size 的有 (boolean)、(number)、(string),它们无法引用其他值,并且始终是叶子节点。
**小提示**: 一个对象的 Retained Size = 该对象的 Shallow Size + 该对象可直接或间接引用的对象的 Shallow Size 之和。Shallow Size == Retained Size 的有 (boolean)、(number)、(string),它们无法引用其他值,并且始终是叶子节点。

我们单击 Retained Size 选择降序展示,可以看到 (closure) 这一项引用的内容达到 98%,继续展开如下:
单击 Retained Size 选择降序展示,可以看到 (closure) 这一项引用的内容达到 98%,继续展开如下:

![](./assets/2.2.2.png)

**可以看出**:一个 leakStr 占了 8% 的内存,而 leakMethod 引用了 81% 的内存。对象保留树(Retainers,老版本 Chrome Object's retaining tree)展示了对象的 GC path,单击如上图中的 leakStr(Distance 是 13),Retainers 会自动展开,Distance 从 13 递减到 1。
**可以看出**:一个 leakStr 占了 8% 的内存,而 leakMethod 引用了 81% 的内存。对象保留树(Retainers,老版本 Chrome 中叫 Object's retaining tree)展示了对象的 GC path,单击如上图中的 leakStr(Distance 是 13),Retainers 会自动展开,Distance 从 13 递减到 1。

我们继续展开 leakMethod,如下所示:
继续展开 leakMethod,如下所示:

![](./assets/2.2.3.png)

Expand All @@ -92,7 +92,7 @@ heapdump-100438986.797085.heapsnapshot

## 2.2.3 对比快照

切换到 Comparison 视图下,可以看到一些 #New、#Deleted、#Delta 等属性,+ 和 - 代表相对于比较的堆快照而言。我们对比第 2 个快照和第 1 个快照,如下所示:
切换到 Comparison 视图下,可以看到 #New、#Deleted、#Delta 等属性,+ 和 - 表示相对于比较的堆快照而言。我们对比第 2 个快照和第 1 个快照,如下所示:

![](./assets/2.2.4.png)

Expand Down
12 changes: 6 additions & 6 deletions 2.3 memwatch-next.md
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
## 2.3.1 使用 memwatch-next

[memwatch-next](https://github.com/marcominetti/node-memwatch)(以下简称 memwatch)是一个用来监测 Node.js 的内存泄漏和堆信息比较的模块。下面我们以一段事件监听器导致内存泄漏的代码为例,讲解如何使用 memwatch。

## 2.3.1 使用 memwatch-next

测试代码如下:

**app.js**
Expand All @@ -28,7 +28,7 @@ const server = http.createServer((req, res) => {
}).listen(3000)
```

在每个请求到来时, server 注册 10000 个 request 事件的监听函数(大量的事件监听函数存储到内存中,造成了内存泄漏),然后手动触发一次 GC。
在每个请求到来时, server 上注册 10000 个 request 事件的监听函数(大量的事件监听函数存储到内存中,从而造成了内存泄漏),然后手动触发一次 GC。

运行该程序:

Expand All @@ -38,7 +38,7 @@ $ node --expose-gc app.js

**注意**:这里添加 --expose-gc 参数启动程序,这样我们才可以在程序中手动触发 GC。

memwatch 可以监听两个事件
memwatch 监听以下两个事件

1. stats:GC 事件,每执行一次 GC,都会触发该函数,打印 heap 相关的信息。如下:

Expand All @@ -55,7 +55,7 @@ memwatch 可以监听两个事件:
}
```

2. leak:内存泄露事件,触发该事件的条件是:连续 5 次 GC 后内存都是增长的。打印如下:
2. leak:内存泄露事件,触发该事件的条件是:内存在连续 5 次 GC 后都是增长的。打印如下:

```js
{
Expand Down Expand Up @@ -176,7 +176,7 @@ memwatch.on('leak', (info) => {

## 2.3.3 结合 heapdump

memwatch 在结合 heapdump 使用时才能发挥更好的作用。通常用 memwatch 监测到发生内存泄漏,用 heapdump 导出多份堆快照,然后用 Chrome DevTools 分析和比较,定位内存泄漏的元凶。
memwatch 在结合 heapdump 使用时才能发挥更好的作用。通常用 memwatch 监测到内存泄漏,用 heapdump 导出多份堆快照,然后用 Chrome DevTools 分析和比较,定位内存泄漏的元凶。

修改代码如下:

Expand Down
Loading

0 comments on commit 3d160c9

Please sign in to comment.