JavaScript 统计不同功能模块的使用时间和占，分析 JavaScript 代码性能和优化方向

场景

2019 年初的时候，做区块链浏览器项目；

项目地址：http://explorer.canonchain.com/

需要做的工作是，前端展示，接口，以及数据获取和写入 SQL；

这个性能分析，是在写 SQL 数据时候需要的，具体的场景如下

后端数据存储

通过请求节点的 JSON RPC 接口获取数据，因为前端需要展示不同维度的数据，所以需要进行数据组装然后写入 SQL（大概需要写入 20 个数据的样子）

做的操作大概如下；

• 读取数据
• 数据过滤和组装
• 写入 SQL 持久化存储

我想要知道性能的瓶颈在哪一步，或者哪一步占用的时间最多，那么就需要搞一个时间分析的模块；

用它跑一下，分析该从哪里入手优化；可以帮助自己写出高性能代码

实现

首先写一个profiler.js文件（源码在文章最后面），然后开始统计

代码：

(async function () {
    let profiler = require("../profiler");
    function sleep(time) {
        return new Promise((resolve) => setTimeout(resolve, time));
    }

    //第一阶段
    profiler.start();
    await sleep(1000 * 3);
    profiler.stop('读取数据');

    //第二阶段
    profiler.start();
    await sleep(1000 * 1);
    profiler.stop('数据过滤和组装');

    //第三阶段
    profiler.start();
    //阿西河前端教程：一个助你成为全栈开发的网站
    await sleep(1000 * 20);
    profiler.stop('写入SQL持久化存储');

    profiler.print();
})();

统计结果

Profiling results:
读取数据:                             3004, Infinity per unit, 12.51%
数据过滤和组装:                          1014, Infinity per unit,  4.22%
写入SQL持久化存储:                      20003, Infinity per unit, 83.27%
total: 24021
{ '读取数据': 3004, '数据过滤和组装': 1014, '写入SQL持久化存储': 20003 }
Infinity per unit

注意事项

如果需要分析某个功能，比如测试一个接口从开始请求到收到结果的时间，单次的结果可能不准确；

但是如果依次去调一万次，然后取平均值，那就非常准确了；

做分析的时候，请注意这一点；（profiler.js支持连续调用 N 次，然后统计 N 次总时间的）

profiler.js 源码

/*jslint node: true */
"use strict";

var count = 0;
var times = {};
var start_ts = 0;

var timers = {};
var timers_results = {};
var profiler_start_ts = Date.now();

function mark_start(tag, id) {
	return;
	if (!id) id = 0;
	if (!timers[tag]) timers[tag] = {};
	if (timers[tag][id])
		throw Error("multiple start marks for " + tag + "[" + id + "]");
	timers[tag][id] = Date.now();
}

function mark_end(tag, id) {
	return;
	if (!timers[tag]) return;
	if (!id) id = 0;
	if (!timers_results[tag])
		timers_results[tag] = [];
	timers_results[tag].push(Date.now() - timers[tag][id]);
	timers[tag][id] = 0;
}

function add_result(tag, consumed_time){
	return;
	if (!timers_results[tag])
		timers_results[tag] = [];
	timers_results[tag].push(consumed_time);
}

function start(){
	if (start_ts)
		throw Error("profiler already started");
	start_ts = Date.now();
}

function stop(tag){
	if (!start_ts)
		throw Error("profiler not started");
	if (!times[tag])
		times[tag] = 0;
	times[tag] += Date.now() - start_ts;
	start_ts = 0;
}

function print(){
	console.log("\nProfiling results:");
	var total = 0;
	for (var tag in times)
		total += times[tag];
	for (var tag in times){
		console.log(
			pad_right(tag+": ", 33) +
			pad_left(times[tag], 5) + ', ' +
			pad_left((times[tag]/count).toFixed(2), 5) + ' per unit, ' +
			pad_left((100*times[tag]/total).toFixed(2), 5) + '%'
		);
	}
	console.log('total: '+total);
	console.log(times);
	console.log(total/count+' per unit');
}

function print_results() {
	console.log("\nBenchmarking results:");
	console.log(times);
	for (var tag in timers_results) {
		var results = timers_results[tag];
		var sum = 0, max = 0, min = 999999999999;
		for (var i = 0; i < results.length; i++) {
			var v = results[i];
			sum += v;
			if (v > max) max = v;
			if (v < min) min = v;
		}
		console.log(tag.padding(50) + ": avg:" + Math.round(sum / results.length).toString().padding(8) + "max:" + Math.round(max).toString().padding(8) + "min:" + Math.round(min).toString().padding(8) + "records:" + results.length);
	}
	var elapsed = Date.now() - profiler_start_ts;
	console.log("\n\nStart time: " + profiler_start_ts + ", End time: " + Date.now() + " Elapsed ms:" + (Date.now() - profiler_start_ts));
	console.log("time in db "+exports.time_in_db+"ms, "+(exports.time_in_db/elapsed*100)+"%");
	if (process.cpuUsage){
		var usage = process.cpuUsage();
		console.log("usage "+usage.user+"mus "+(usage.user/1000/elapsed*100)+"%, sys "+usage.system+"mus "+(usage.system/1000/elapsed*100)+"%, total "+((usage.system+usage.user)/1000/elapsed*100)+"%");
	}
}

function pad_right(str, len){
	if (str.length >= len)
		return str;
	return str + ' '.repeat(len - str.length);
}

function pad_left(str, len){
	str = str+'';
	if (str.length >= len)
		return str;
	return ' '.repeat(len - str.length) + str;
}

function increment(){
	count++;
}

process.on('SIGINT', function(){
	console.log = clog;
	console.log("received sigint");
	//print();
	print_results();
	process.exit();
});

String.prototype.padding = function(n, c)
{
        var val = this.valueOf();
        if ( Math.abs(n) <= val.length ) {
                return val;
        }
        var m = Math.max((Math.abs(n) - this.length) || 0, 0);
        var pad = Array(m + 1).join(String(c || ' ').charAt(0));
//      var pad = String(c || ' ').charAt(0).repeat(Math.abs(n) - this.length);
        return (n < 0) ? pad + val : val + pad;
//      return (n < 0) ? val + pad : pad + val;
};

var clog = console.log;
//console.log = function(){};

exports.start = start;
exports.stop = stop;
exports.increment = increment;
exports.print = print;
exports.mark_start = mark_start;
exports.mark_end = mark_end;
exports.add_result = add_result;
exports.time_in_db = 0;

// exports.start = function(){};
// exports.stop = function(){};
// exports.increment = function(){};
//exports.print = function(){};

关键知识点

• JS 中 sleep 实现