从零搭建 Node.js 企业级 Web 服务器(十三):断点调试与性能分析

断点调试

Node.js 官方提供了断点调试机制,出于安全性考虑默认为关闭状态,可以通过 node 参数 --inspect--inspect-brk 开启,配合 IDE 能够非常方便地调试代码,本章就上一章已完成的项目 host1-tech/nodejs-server-examples - 12-rpc 基于 Visual Studio Code 进行断点调试:

$ mkdir .vscode # 新建 .vsocde 目录存放 vscode 工作空间级配置

$ tree -L 1 -a # 展示包括 . 开头的全部目录内容结构

.

├── .dockerignore

├── .env

├── .env.local

├── .env.production.local

├── .npmrc

├── .sequelizerc

├── .vscode

├── Dockerfile

├── database

├── node_modules

├── package.json

├── public

├── scripts

├── src

└── yarn.lock

创建 .vscode/launch.json(方法有很多种,此处不再展开):

// .vscode/launch.json

{

// Use IntelliSense to learn about possible attributes.

// Hover to view descriptions of existing attributes.

// For more information, visit: https://go.microsoft.com/fwlink/?linkid=830387

"version": "0.2.0",

"configurations": [

{

"name": "Attach by Process ID",

"processId": "${command:PickProcess}",

"request": "attach",

"skipFiles": ["<node_internals>/**"],

"type": "pwa-node"

}

]

}

启动参数 --inspect--inspect-brk 都可以开启调试状态,相比而言,后者在 Node.js 程序启动时立即进入断点等待,给了开发者调试启动过程的机会,本章采用 --inspect-brk 写入调试入口:

// package.json

{

"name": "13-debugging-and-profiling",

"version": "1.0.0",

"scripts": {

"start": "node -r ./scripts/env src/server.js",

+ "start:inspect": "node --inspect-brk -r ./scripts/env src/server.js",

"start:prod": "cross-env NODE_ENV=production node -r ./scripts/env src/server.js",

"sequelize": "sequelize",

"sequelize:prod": "cross-env NODE_ENV=production sequelize",

"build:yup": "rollup node_modules/yup -o src/moulds/yup.js -p @rollup/plugin-node-resolve,@rollup/plugin-commonjs,rollup-plugin-terser -f umd -n 'yup'"

},

// ...

}

接下来通过 yarn start:inspect 启动程序并使用 Visual Studio Code 进行断点调试:

$ yarn start:inspect | yarn bunyan -o short

# ...

Debugger listening on ws://127.0.0.1:9229/35a82bee-093c-491d-9d54-4cca9a142cbf

For help, see: https://nodejs.org/en/docs/inspector

f37440bf31eb599135efeb171cc0fcdf6ff7fac8.jpg

性能分析

服务器的性能瓶颈根据应用场景不同通常不尽相同,但最常见的性能瓶颈主要出现在并发量上,其中,每秒请求数(简称 RPS)便是衡量并发量的主要指标,为了方便对照参考,先对淘宝首页进行 RPS 测试:

$ yarn add -D autocannon # 本地安装 RPS 测试工具 autocannon

# ...

info Direct dependencies

└─ autocannon@5.0.1

# ...

$ yarn autocannon https://www.taobao.com/ # 对淘宝首页发起 RPS 测试

# ...

Running 10s test @ https://www.taobao.com/

10 connections

┌─────────┬───────┬───────┬────────┬────────┬───────────┬──────────┬───────────┐

│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │

├─────────┼───────┼───────┼────────┼────────┼───────────┼──────────┼───────────┤

│ Latency │ 36 ms │ 90 ms │ 267 ms │ 523 ms │ 106.68 ms │ 70.25 ms │ 586.13 ms │

└─────────┴───────┴───────┴────────┴────────┴───────────┴──────────┴───────────┘

┌───────────┬─────────┬─────────┬─────────┬─────────┬─────────┬────────┬─────────┐

│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │

├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼────────┼─────────┤

│ Req/Sec │ 81 │ 81 │ 95 │ 99 │ 92.7 │ 5.18 │ 81 │

├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼────────┼─────────┤

│ Bytes/Sec │ 9.93 MB │ 9.93 MB │ 11.6 MB │ 12.1 MB │ 11.4 MB │ 636 kB │ 9.93 MB │

└───────────┴─────────┴─────────┴─────────┴─────────┴─────────┴────────┴─────────┘

Req/Bytes counts sampled once per second.

927 requests in 10.07s, 114 MB read

淘宝拥有一套非常完善的负载均衡策略,以上数据不能代表整个集群的并发量,但是一定程度上代表了单个容器的数值,RPS 均值 92.7。

现在再测试一下自己的服务器,

通过浏览器登录获取 Cookie 中的会话 ID:

0cba81803147903255fc64e107f582281ba4b666.jpg

对自己的服务器首页发起 RPS 测试:

$ # 对自己的服务器首页发起 RPS 测试

$ yarn autocannon -H 'Cookie: connect.sid=s%3AY2A4lo84OOtXCYgc3LRft03HtRaC4ieZ.kW%2BJlJIhSUQTOCxpREjtByDm8QmmA%2FPsNvddYQSP1fM' http://localhost:9000/

# ...

Running 10s test @ http://localhost:9000/

10 connections

┌─────────┬────────┬────────┬────────┬────────┬───────────┬──────────┬───────────┐

│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │

├─────────┼────────┼────────┼────────┼────────┼───────────┼──────────┼───────────┤

│ Latency │ 122 ms │ 197 ms │ 276 ms │ 306 ms │ 197.71 ms │ 38.14 ms │ 343.02 ms │

└─────────┴────────┴────────┴────────┴────────┴───────────┴──────────┴───────────┘

┌───────────┬─────────┬─────────┬─────────┬─────────┬─────────┬────────┬─────────┐

│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │

├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼────────┼─────────┤

│ Req/Sec │ 46 │ 46 │ 50 │ 57 │ 50.1 │ 2.92 │ 46 │

├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼────────┼─────────┤

│ Bytes/Sec │ 44.2 kB │ 44.2 kB │ 48.1 kB │ 54.8 kB │ 48.1 kB │ 2.8 kB │ 44.2 kB │

└───────────┴─────────┴─────────┴─────────┴─────────┴─────────┴────────┴─────────┘

Req/Bytes counts sampled once per second.

501 requests in 10.06s, 481 kB read

发现 RPS 均值仅有 50.1,怀疑存在性能瓶颈。这里使用 0x 采集生成火焰图来定位问题,安装 0x 并写入启动入口:

$ yarn add -D 0x # 本地安装 0x

# ...

info Direct dependencies

└─ 0x@4.9.1

info All dependencies

# ...

// package.json

{

"name": "13-debugging-and-profiling",

"version": "1.0.0",

"scripts": {

"start": "node -r ./scripts/env src/server.js",

"start:inspect": "node --inspect-brk -r ./scripts/env src/server.js",

+ "start:profile": "0x -- node -r ./scripts/env src/server.js",

"start:prod": "cross-env NODE_ENV=production node -r ./scripts/env src/server.js",

"sequelize": "sequelize",

"sequelize:prod": "cross-env NODE_ENV=production sequelize",

"build:yup": "rollup node_modules/yup -o src/moulds/yup.js -p @rollup/plugin-node-resolve,@rollup/plugin-commonjs,rollup-plugin-terser -f umd -n 'yup'"

},

// ...

}

通过 yarn start:profile 启动服务器并改用 60 秒测试 RPS,测试时间越长噪音越小:

# Tab 1

$ yarn start:profile | yarn bunyan -o short

🔥 Profiling

# ...

# Tab 2

$ # 对自己的服务器首页发起 RPS 测试

$ yarn autocannon -d 60 -H 'Cookie: connect.sid=s%3AY2A4lo84OOtXCYgc3LRft03HtRaC4ieZ.kW%2BJlJIhSUQTOCxpREjtByDm8QmmA%2FPsNvddYQSP1fM' http://localhost:9000/

# ...

关闭服务器并打开火焰图:

# Tab 1

$ yarn start:profile | yarn bunyan -o short

🔥 Profiling

# ...

^C

🔥 Waiting for subprocess to exit...

🔥 Flamegraph generated in ... 79929.0x/flamegraph.html

$ open 79929.0x/flamegraph.html # 用浏览器打开 *.0x 目录下的 flamegraph.html 文件

火焰图是根据程序的栈的状态对出现函数的采样数据统计而得,宽度代表函数运行一次所需的时长、高度代表栈的层数、颜色深度代表函数在采样中出现的频率,因此宽度最长颜色最深的方块对性能影响最大。0x 生成的火焰图默认以 *~ 符号区别展示了 V8 优化过的函数与未优化的函数,通过点击 Merge 合并两者(0x 生成的火焰图界面详情参考 0x UI):

b515e414cbb2755575bfbdf823d65cf87c197482.jpg

分析发现 sequelize 的 Model#findOne 方法被 express-session 大量调用,推断可能是 connect-session-sequelize 作为 express-session 的 store 引起的,因此尝试以 redis 作为会话缓存进行优化:

$ yarn add redis connect-redis # 本地安装 redis、connect-redis

# ...

info Direct dependencies

├─ connect-redis@5.0.0

└─ redis@3.0.2

# ...

$ # 以镜像 redis:6.0.6 启动 redis 服务,命名为 redis6

$ docker run -p 6379:6379 -d --name redis6 redis:6.0.6

// src/config/index.js

// ...

const config = {

// 默认配置

default: {

// ...

+

+ redisOptions: {

+ host: 'localhost',

+ port: 6379,

+ },

},

// ...

};

// ...

# .env

LOG_LEVEL='debug'

GRPC_TRACE='all'

GRPC_VERBOSITY='DEBUG'

+

+WITH_REDIS=1

// src/middlewares/session.js

const session = require('express-session');

const sessionSequelize = require('connect-session-sequelize');

+const redis = require('redis');

+const sessionRedis = require('connect-redis');

const { sequelize } = require('../models');

-const { sessionCookieSecret, sessionCookieMaxAge } = require('../config');

+const {

+ redisOptions,

+ sessionCookieSecret,

+ sessionCookieMaxAge,

+} = require('../config');

+const { name } = require('../../package.json');

module.exports = function sessionMiddleware() {

- const SequelizeStore = sessionSequelize(session.Store);

-

- const store = new SequelizeStore({

- db: sequelize,

- modelKey: 'Session',

- tableName: 'session',

- });

+ let store;

+

+ if (process.env.WITH_REDIS) {

+ const client = redis.createClient(redisOptions);

+ const RedisStore = sessionRedis(session);

+ store = new RedisStore({ client, prefix: name });

+ } else {

+ const SequelizeStore = sessionSequelize(session.Store);

+ store = new SequelizeStore({

+ db: sequelize,

+ modelKey: 'Session',

+ tableName: 'session',

+ });

+ }

return session({

secret: sessionCookieSecret,

cookie: { maxAge: sessionCookieMaxAge },

store,

resave: false,

proxy: true,

saveUninitialized: false,

});

};

再次测试 RPS:

c9d5411643c38d466ffdfa6b7fefff523eb97c71.jpg

$ # 对自己的服务器首页发起 RPS 测试

$ yarn autocannon -H 'Cookie: connect.sid=s%3As4C-tLD4Xf8q3zjmtQ3k4B62mTZZNzfw.OdVLDs08H1YCXyZXIBgRuzE%2FE%2FH1BwDH4ynxEBNlKkg' http://localhost:9000/

# ...

Running 10s test @ http://localhost:9000/

10 connections

┌─────────┬──────┬──────┬───────┬───────┬─────────┬─────────┬─────────┐

│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │

├─────────┼──────┼──────┼───────┼───────┼─────────┼─────────┼─────────┤

│ Latency │ 6 ms │ 9 ms │ 18 ms │ 20 ms │ 9.35 ms │ 3.25 ms │ 34.4 ms │

└─────────┴──────┴──────┴───────┴───────┴─────────┴─────────┴─────────┘

┌───────────┬────────┬────────┬────────┬─────────┬─────────┬────────┬────────┐

│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │

├───────────┼────────┼────────┼────────┼─────────┼─────────┼────────┼────────┤

│ Req/Sec │ 720 │ 720 │ 1035 │ 1190 │ 1014.82 │ 160.17 │ 720 │

├───────────┼────────┼────────┼────────┼─────────┼─────────┼────────┼────────┤

│ Bytes/Sec │ 692 kB │ 692 kB │ 995 kB │ 1.14 MB │ 975 kB │ 154 kB │ 692 kB │

└───────────┴────────┴────────┴────────┴─────────┴─────────┴────────┴────────┘

Req/Bytes counts sampled once per second.

11k requests in 11.04s, 10.7 MB read

发现 RPS 均值提升到了 1003.89,表明推断正确。现在再使用 Node.js 内置的 cluster 机制提高 CPU 利用率进一步优化,此处注意合理设置 worker 数量,如果 worker 数量过高会因为操作系统过于频繁的调度反而降低性能:

# .env

LOG_LEVEL='debug'

GRPC_TRACE='all'

GRPC_VERBOSITY='DEBUG'

WITH_REDIS=1

+

+CLUSTERING=2

// src/server.js

+const os = require('os');

+const cluster = require('cluster');

const express = require('express');

const { resolve } = require('path');

const { promisify } = require('util');

const initMiddlewares = require('./middlewares');

const initControllers = require('./controllers');

const initSchedules = require('./schedules');

const initRpc = require('./rpc');

const logger = require('./utils/logger');

// ...

async function bootstrap() {

// ...

}

// ...

-bootstrap();

+const useCluster = Boolean(process.env.CLUSTERING);

+

+if (useCluster && cluster.isMaster) {

+ const forkCount = parseInt(process.env.CLUSTERING) || os.cpus().length;

+

+ for (let i = 0, n = forkCount; i < n; i++) {

+ cluster.fork();

+ }

+

+ cluster.on('online', (worker) => {

+ logger.info(`> Worker ${worker.process.pid} is running`);

+ });

+

+ cluster.on('exit', (worker) => {

+ logger.info(`> Worker ${worker.process.pid} exited`);

+ process.exit(worker.process.exitCode);

+ });

+} else {

+ bootstrap();

+}

再次测试 RPS:

$ # 对自己的服务器首页发起 RPS 测试

$ yarn autocannon -H 'Cookie: connect.sid=s%3As4C-tLD4Xf8q3zjmtQ3k4B62mTZZNzfw.OdVLDs08H1YCXyZXIBgRuzE%2FE%2FH1BwDH4ynxEBNlKkg' http://localhost:9000/

# ...

Running 10s test @ http://localhost:9000/

10 connections

┌─────────┬──────┬──────┬───────┬───────┬─────────┬─────────┬──────────┐

│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │

├─────────┼──────┼──────┼───────┼───────┼─────────┼─────────┼──────────┤

│ Latency │ 4 ms │ 7 ms │ 14 ms │ 17 ms │ 7.77 ms │ 2.74 ms │ 44.46 ms │

└─────────┴──────┴──────┴───────┴───────┴─────────┴─────────┴──────────┘

┌───────────┬────────┬────────┬─────────┬─────────┬─────────┬────────┬────────┐

│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │

├───────────┼────────┼────────┼─────────┼─────────┼─────────┼────────┼────────┤

│ Req/Sec │ 1009 │ 1009 │ 1209 │ 1430 │ 1208.41 │ 117.95 │ 1009 │

├───────────┼────────┼────────┼─────────┼─────────┼─────────┼────────┼────────┤

│ Bytes/Sec │ 970 kB │ 970 kB │ 1.16 MB │ 1.38 MB │ 1.16 MB │ 114 kB │ 970 kB │

└───────────┴────────┴────────┴─────────┴─────────┴─────────┴────────┴────────┘

Req/Bytes counts sampled once per second.

12k requests in 10.04s, 11.6 MB read

发现 RPS 均值已经达到 1208.41,并发量已稳达千级,符合期望。接下来再看一看数据库查询接口的 RPS 情况,测试 /api/shop

$ # 对自己的服务器 /api/shop 发起 RPS 测试

$ yarn autocannon -H 'Cookie: connect.sid=s%3ArGA44wXyem3dChGhc4PTIgAnyUJ8Dj2N.7hd9jyemRgD8CskqEUSjTGSSl%2FguJsKaAdienAyO7O8' http://localhost:9000/api/shop

# ...

Running 10s test @ http://localhost:9000/api/shop

10 connections

┌─────────┬───────┬───────┬───────┬───────┬──────────┬────────┬──────────┐

│ Stat │ 2.5% │ 50% │ 97.5% │ 99% │ Avg │ Stdev │ Max │

├─────────┼───────┼───────┼───────┼───────┼──────────┼────────┼──────────┤

│ Latency │ 15 ms │ 23 ms │ 41 ms │ 46 ms │ 24.18 ms │ 6.7 ms │ 85.78 ms │

└─────────┴───────┴───────┴───────┴───────┴──────────┴────────┴──────────┘

┌───────────┬────────┬────────┬────────┬────────┬────────┬─────────┬────────┐

│ Stat │ 1% │ 2.5% │ 50% │ 97.5% │ Avg │ Stdev │ Min │

├───────────┼────────┼────────┼────────┼────────┼────────┼─────────┼────────┤

│ Req/Sec │ 361 │ 361 │ 399 │ 441 │ 404.9 │ 26.06 │ 361 │

├───────────┼────────┼────────┼────────┼────────┼────────┼─────────┼────────┤

│ Bytes/Sec │ 312 kB │ 312 kB │ 345 kB │ 381 kB │ 349 kB │ 22.5 kB │ 312 kB │

└───────────┴────────┴────────┴────────┴────────┴────────┴─────────┴────────┘

Req/Bytes counts sampled once per second.

4k requests in 10.05s, 3.49 MB read

/api/shop 的 RPS 均值为 404.9,已经接近单个 sqlite 数据库所能提供的并发上限,符合期望。

考虑到 Node.js 的 cluster 机制在调试与分析时会带来许多不便,找到对应的启动入口使用环境变量关闭 cluster 机制:

// package.json

{

"name": "13-debugging-and-profiling",

"version": "1.0.0",

"scripts": {

"start": "node -r ./scripts/env src/server.js",

- "start:inspect": "node --inspect-brk -r ./scripts/env src/server.js",

+ "start:inspect": "cross-env CLUSTERING='' node --inspect-brk -r ./scripts/env src/server.js",

- "start:profile": "0x -- node -r ./scripts/env src/server.js",

+ "start:profile": "cross-env CLUSTERING='' 0x -- node -r ./scripts/env src/server.js",

"start:prod": "cross-env NODE_ENV=production node -r ./scripts/env src/server.js",

"sequelize": "sequelize",

"sequelize:prod": "cross-env NODE_ENV=production sequelize",

"build:yup": "rollup node_modules/yup -o src/moulds/yup.js -p @rollup/plugin-node-resolve,@rollup/plugin-commonjs,rollup-plugin-terser -f umd -n 'yup'"

},

// ...

}

本章源码

host1-tech/nodejs-server-examples - 13-debugging-and-profiling

更多阅读

从零搭建 Node.js 企业级 Web 服务器(零):静态服务
从零搭建 Node.js 企业级 Web 服务器(一):接口与分层
从零搭建 Node.js 企业级 Web 服务器(二):校验
从零搭建 Node.js 企业级 Web 服务器(三):中间件
从零搭建 Node.js 企业级 Web 服务器(四):异常处理
从零搭建 Node.js 企业级 Web 服务器(五):数据库访问
从零搭建 Node.js 企业级 Web 服务器(六):会话
从零搭建 Node.js 企业级 Web 服务器(七):认证登录
从零搭建 Node.js 企业级 Web 服务器(八):网络安全
从零搭建 Node.js 企业级 Web 服务器(九):配置项
从零搭建 Node.js 企业级 Web 服务器(十):日志
从零搭建 Node.js 企业级 Web 服务器(十一):定时任务
从零搭建 Node.js 企业级 Web 服务器(十二):远程调用
从零搭建 Node.js 企业级 Web 服务器(十三):断点调试与性能分析

以上是 从零搭建 Node.js 企业级 Web 服务器(十三):断点调试与性能分析 的全部内容, 来源链接: utcz.com/a/37430.html

回到顶部