Last week, before the system went live, we ran a pressure test to see how much concurrency and concurrent load the system could handle. In the process of pressure test, found that the CPU of the server is very high, and TPS, interface time, service availability and so on are normal, oh, my god, this is strange, I thought for a long time did not come up with why, had to ask for help, the boss said to check the CPU processor what? What is this?? Although I don’t understand, but you can check in (╯ the ╰)╮, can not wait for me to find out, big guy directly start, a SAO operation, they found out the reason ~ this really let their shame ah, internal work is far from enough ah, back online to find information, make up a how to analyze node project performance problems
In the development process, because too much attention is paid to the implementation of business logic, some possible performance points are ignored, and these points can only appear in a slightly larger amount of concurrent scenarios, forget where to see a sentence may be a problem point, it will be a problem performance problem analysis is essential
The sample project
To illustrate, I’ve written a simple little example
// app.js
const crypto = require('crypto')
const Koa = require('koa')
const Router = require('koa-router');
const app = new Koa();
const router = new Router();
router.get('/crypto'.async(ctx, next) => {
const salt = crypto.randomBytes(128).toString('base64')
const hash = crypto.pbkdf2Sync('crypto', salt, 10000.64.'sha512').toString('hex')
ctx.body = { hash: hash }
console.log(hash)
ctx.status = 200
next()
});
let reqNum = 0
router.get('/empty'.async(ctx, next) => {
ctx.body = { hash: 'empty' }
reqNum++;
ctx.status = 200
next()
});
app.use(router.routes()).use(router.allowedMethods());
app.listen(3000, () = > {console.log("listen 3000")})Copy the codeBased on KOA2, there are two routes, one /crypto, where the business logic is to use the crypto library to encrypt the string; One is /empty, which is an empty interface with no business logic
Pressure test
Fast HTTP/1.1 Benchmarking Tool written in Node.js Is a fast HTTP/1.1 benchmarking tool written in Node.js. Autocannon is a stress testing tool written in node.js. Pressure tools written with Node can generate more load than WRK.
install
npm i autocannon -g npm i autocannon --save
use
Two ways of use are provided
- The command line
Autocannon - 5-100 - d c p 2 http://127.0.0.1:3000/testSimple and quick - API call
autocannon(opts[, cb])Easy scripting
There are several key parameters
-c/--connections NUMNumber of concurrent connections, default 10-p/--pipelining NUMNumber of pipeline requests per connection. The default 1-d/--duration SECExecution time, in seconds-m/--method METHODThe default request type is GET-b/--body BODYRequest form
There are many more parameters, you can check out the documentation on the official website.
The library currently supports only one interface compaction. I wrote a script that supports batch compaction and generating test reports. See the code at the end of this article.
report
Below is for/the empty interface pressure measuring autocannon – 5-100 – c d p 1 http://127.0.0.1:3000/empty results are as follows
As you can see, 100 links per second, one request per link for 5 seconds, generating 31K requests in total. The report is divided into three parts, with the first line representing the latency of the interface, the second line representing requests per second (TPS), and the third line representing bytes returned per second. Therefore, the lower the latency, the higher the TPS, the better the interface performance, because empty is an empty interface, so its TPS =6221 is not bad, the response time is also very fast, let’s try /crypto interface
The TPS of this interface is only 77, and the interface time is up to 1100ms, indicating that this interface has a lot of room for optimization
Generate performance files and analysis
Through the pressure test tool we found the problem of the interface, then, it is necessary to analyze the interface, but just look at the interface code, it is not good to analyze ah, after all, it is not convincing, we need a performance report, with data to speak, the following two methods to you
V8 Profiler
V8 official has taken this into account for you to provide a Profiler tool is very fast, the steps are as follows (app.js as an example)
Generate a report
If you add –prof to the startup command, such as node –prof app.js, a file in the root directory of the project will be generated in the format of the isolate- XXXXXXX-v8.log, which records the call stack and time during the run.
V8 - version 6,1,534,47,0 Shared library,"C:\Program Files\nodejs\node.exe"X7ff7505f0000, 0, 0 x7ff751c0f000, 0 Shared - library,"C:\WINDOWS\SYSTEM32\ntdll.dll"X7ff8718a0000, 0, 0 x7ff871a61000, 0 Shared - library,"C:\WINDOWS\system32\KERNEL32.DLL"X7ff870590000, 0, 0 x7ff87063d000, 0 Shared - library,"C:\WINDOWS\system32\KERNELBASE.dll"X7ff86e830000, 0, 0 x7ff86ea18000, 0 Shared - library,"C:\WINDOWS\system32\WS2_32.dll"X7ff86ee00000, 0, 0 x7ff86ee6b000, 0Copy the codeAnalysis report
- To analyze the log file just generated, use the tool provided by the official
node --prof-process isolate-xxxxxxxx-v8.log, produces the following result (discard the useless parts)
Statistical profiling result from isolate-00000209B99A60A0-v8.log, (17704 ticks, 8 unaccounted, 0 excluded). [Shared libraries]: Ticks total nonlib name 13795 77.9% C:\WINDOWS\SYSTEM32\ ntdL.dll... [JavaScript]: Ticks total Nonlib name 12 0.1% 11.3% Builtin: CallFunction_ReceiverIsAny... [C++]: ticks total nonlib name [Summary]: Ticks total nonlib name 98 ticks total nonlib name 98 ticks JavaScript 0 0.0% 0.0% C++ 8 0.0% 7.5% GC 17598 99.4% Shared libraries 8 0.0% Unaccounted [C++ entry points]: ticks cpp total name [Bottom up (heavy) profile]: Note: percentage shows a share of a particularcaller inThe total amount of its parent Callers evicted less than 1.0% are not shown. Ticks parent name 13795 77.9% Exe 3768 99.3% C: Program Files\nodejs\node.exe 3768 99.3% C: Program Files\nodejs\node.exe Function: ~pbkdf2 crypto.js:633:16 ~ exports.pbkdf2sync crypto.js: 620:30 3287 ~router. Get D:\github\ webApp \js\usen\app.js: 8:233287 100.0% Function: To dispatch the D: \ lot \ webapp/js/usen \ node_modules \ _koa - [email protected] @ koa - compose \ index js: he...Copy the codeThe report consists of six parts: Shared libraries, JavaScript, C++, Summary, C++ entry points and Bottom up (heavy) profile, The [JavaScript] section lists the CPU ticks consumed by JavaScript code execution, the [C++] section lists the CPU ticks consumed by C++ code execution, and the [Summary] section lists the percentage of CPU ticks consumed by C++ code execution. [Bottom Up] lists all functions and stack information in order of CPU usage time.
Function: ~pbkdf2 crypto.js:633:16 this Function consumes 87.2% of the CPU
- File way is not intuitive, so let’s change the UI interface, the steps are as follows
- First clone V8 warehouse down
git clone https://github.com/v8/v8.git - Convert log files to JSON format
node --prof-process --preprocess isolate-xxxxxxxxxx-v8.log > v8.json - Open the
v8/tools/profview/index.htmlFile is a static interface. Select the newly generated v8. Json file in the center of the interface
The specific functions are not explained one by one, but we go layer by layer to find the point of time, and we quickly find the CPU consumption, as shown in the figure below
Node accounts for 45%, of which pbkdf2 crypto.js accounts for 92%
v8-profiler
In addition to the official offering, we can also choose the open source guru’s library, V8-Profiler, which was created six years ago, the last one was a year and a half ago, and the community reviews are good
Generate a report
The generation method is simple, but the disadvantage is that it needs to be hard-coded in the project as follows
profiler.startProfiling(' '.true);
setTimeout(function() {
var profile = profiler.stopProfiling(' ');
profile.export()
.pipe(fs.createWriteStream(`cpuprofile-The ${Date.now()}.cpuprofile`))
.on('finish', () => profile.delete())
}, 1000);
Copy the codeAnalytical report
- Chrome
In Chrome’s console, there is a column of JavaScript profiles as shown below
Click Load, select the file you just generated, and parse it as follows
Layer by layer, you know
- Figure flamegraph – flame
Use Flamegraph to generate a cool fire graph, which is cool to use in reports
I won’t go into details about how to use it
- v8-analytics
This is an open source library v8-Analytics written by the community leaders. The official introduction is as follows
Parsing CPU & heap-memory logs output by tools such as V8-profiler and Heapdump can be provided
- V8 engine inverse optimization or optimization failure function is displayed in red and optimization failure reason is displayed
- The function execution time exceeding expectations is shown in red
- A display of suspected memory leaks in the current project
The corresponding command is as follows
Va test Bailout — Only This command lists only the functions that were inverse optimised by the V8 engine.
Va test timeout 200 –only This command displays functions that are held for more than 200ms.
Va Test Leak suspiciously shows a suspected memory leak in the tested HeapSnapshot file.
The advantage of this library is that we do not have to go to the search, which can be more convenient for us to filter the problem
Batch pressure test and generate report
Autocannon can only run one interface, so to test the next interface, you have to change the code. For example, if you want to test multiple interfaces in batches, you need to change the code back and forth, which is difficult to operate, so I wrote a script based on Autocannon that can measure the good interfaces one by one and generate test reports.
'use strict'
const autocannon = require('autocannon')
const reporter = require('autocannon-reporter')
const path = require('path')
const sleep = ms= > new Promise(resolve= > setTimeout(resolve, ms));
/** * @description * Run autocannon * @author lizc * @param {*} param */
function makeAutocannon(param) {
autocannon(param).on('done', handleResults)
}
* @author lizc * @param {*} result */
function handleResults(result) {
const reportOutputPath = path.join(`. /${result.title}_report.html`)
reporter.writeReport(reporter.buildReport(result), reportOutputPath, (err, res) => {
if (err) console.err('Error writting report: ', err)
else console.log('Report written to: ', reportOutputPath)
})
}
// Request parameters
const autocannonParam = {
url: 'http://127.0.0.1:6100/'.connections: 100.duration: 10.headers: {
type: 'application/x-www-form-urlencoded'}}// Request message parameters
const requestsParam = {
method: 'POST'.// this should be a put for modifying secret details
headers: { // let submit some json?
'Content-type': 'application/json; charset=utf-8'}}/** * @description * Start batch pressure * @author lizc * @param {*} Interface list */
async function run(methodList) {
const autocannonList = methodList.map(val= > {
return {
...autocannonParam,
url: autocannonParam.url + val,
title: val,
requests: [
{
...requestsParam,
}
],
}
})
for (let i = 0; i < autocannonList.length; i++) {
if(i ! = =0) {
await sleep((autocannonList[i - 1].duration + 2) * 1000)
makeAutocannon(autocannonList[i])
} else {
makeAutocannon(autocannonList[i])
}
}
}
/ / start
run(['order'.'crypto'])
Copy the codesummary
I’m a github porter
The above method can basically meet our needs, of course, performance involves many aspects such as memory leaks, things, performance tuning road long ah, most of the things are from the big guys summary, I just do a summary, easy to understand and refer to their own, I hope to help partners ~
Refer to the link
Github.com/nswbmw/node…
Github.com/hyj1991/v8-…
Cnodejs.org/topic/58b56…
Github.com/mcollina/au…
www.helplib.com/GitHub/arti…
Github.com/nearform/no…