ehm*_*cky 8 javascript benchmarking asynchronous async-await
我想计算异步函数（async/ await）在JavaScript中花费了多长时间。
一个可以做：
const asyncFunc = async function () {};
const before = Date.now();
asyncFunc().then(() => {
const after = Date.now();
console.log(after - before);
});
但是，这不起作用，因为promise回调在新的微任务中运行。即，在asyncFunc()的开始和结束之间then(() => {})，将首先触发任何已排队的微任务，并考虑其执行时间。
例如：
const asyncFunc = async function () {};
const slowSyncFunc = function () {
for (let i = 1; i < 10 ** 9; i++) {}
};
process.nextTick(slowSyncFunc);
const before = Date.now();
asyncFunc().then(() => {
const after = Date.now();
console.log(after - before);
});
这会1739在我的机器上打印，即将近2秒钟，因为它等待slowSyncFunc()完成，这是错误的。
请注意，我不想修改的主体asyncFunc，因为我需要检测许多异步函数而无须修改每个函数。否则，我只能Date.now()在的开头和结尾添加一条语句asyncFunc。
还要注意，问题不在于如何检索性能计数器。使用Date.now()，console.time()，process.hrtime()（Node.js的只），或performance（浏览器只）不会改变这个问题的基础。问题在于承诺回调在新的微任务中运行的事实。如果在原始示例中添加类似setTimeout或的语句process.nextTick，那么您正在修改问题。
任何已经排队的微任务将首先被触发，并且它们的执行时间将被考虑在内。
是的，而且没有办法解决。如果您不想让其他任务对您的测量有贡献，请不要排队。这是唯一的解决办法。
这不是承诺（或async functions）或微任务队列的问题，这是所有在任务队列上运行回调的异步事物共有的问题。
我们遇到的问题
\n\nprocess.nextTick(() => {/* hang 100ms */})\nconst asyncFunc = async () => {/* hang 10ms */}\nconst t0 = /* timestamp */\nasyncFunc().then(() => {\n const t1 = /* timestamp */\n const timeUsed = t1 - t0 /* 110ms because of nextTick */\n /* WANTED: timeUsed = 10ms */\n})\n解决方案（想法）
\n\nconst AH = require(\'async_hooks\')\nconst hook = /* AH.createHook for\n 1. Find async scopes that asycnFunc involves ... SCOPES\n (by handling \'init\' hook)\n 2. Record time spending on these SCOPES ... RECORDS \n (by handling \'before\' & \'after\' hook) */\nhook.enable()\nasyncFunc().then(() => {\n hook.disable()\n const timeUsed = /* process RECORDS */\n})\n但这不会捕获第一个同步操作；即假设asyncFunc如下，$1$不会添加到 SCOPES（因为它是同步操作，async_hooks 不会初始化新的异步范围），然后永远不会将时间记录添加到 RECORDS
hook.enable()\n/* A */\n(async function asyncFunc () { /* B */\n /* hang 10ms; usually for init contants etc ... $1$ */ \n /* from async_hooks POV, scope A === scope B) */\n await /* async scope */\n}).then(..)\n要记录这些同步操作，一个简单的解决方案是通过包装到setTimeout. 这个额外的东西确实需要时间来运行，忽略它，因为值很小
hook.enable()\n/* force async_hook to \'init\' new async scope */\nsetTimeout(() => { \n const t0 = /* timestamp */\n asyncFunc()\n .then(()=>{hook.disable()})\n .then(()=>{\n const timeUsed = /* process RECORDS */\n })\n const t1 = /* timestamp */\n t1 - t0 /* ~0; note that 2 `then` callbacks will not run for now */ \n}, 1)\n请注意，解决方案是“测量异步函数涉及的同步操作所花费的时间”，异步操作（例如超时空闲）不会计算在内，例如
\n\nasync () => {\n /* hang 10ms; count*/\n await new Promise(resolve => {\n setTimeout(() => {\n /* hang 10ms; count */\n resolve()\n }, 800/* NOT count*/)\n }\n /* hang 10ms; count*/\n}\n// measurement takes 800ms to run\n// timeUsed for asynFunc is 30ms\n最后，我认为也许可以以包括同步和异步操作的方式来测量异步函数（例如可以确定800ms），因为async_hooks确实提供了调度的详细信息，例如，setTimeout(f, ms)async_hooks将初始化“超时”类型的异步范围，调度详细信息，可以在以下位置ms找到：resource._idleTimeoutinit(,,,resource) hook
演示（在nodejs v8.4.0上测试）
\n\n// measure.js\nconst { writeSync } = require(\'fs\')\nconst { createHook } = require(\'async_hooks\')\n\nclass Stack {\n constructor() {\n this._array = []\n }\n push(x) { return this._array.push(x) }\n peek() { return this._array[this._array.length - 1] }\n pop() { return this._array.pop() }\n get is_not_empty() { return this._array.length > 0 }\n}\n\nclass Timer {\n constructor() {\n this._records = new Map/* of {start:number, end:number} */\n }\n starts(scope) {\n const detail =\n this._records.set(scope, {\n start: this.timestamp(),\n end: -1,\n })\n }\n ends(scope) {\n this._records.get(scope).end = this.timestamp()\n }\n timestamp() {\n return Date.now()\n }\n timediff(t0, t1) {\n return Math.abs(t0 - t1)\n }\n report(scopes, detail) {\n let tSyncOnly = 0\n let tSyncAsync = 0\n for (const [scope, { start, end }] of this._records)\n if (scopes.has(scope))\n if (~end) {\n tSyncOnly += end - start\n tSyncAsync += end - start\n const { type, offset } = detail.get(scope)\n if (type === "Timeout")\n tSyncAsync += offset\n writeSync(1, `async scope ${scope} \\t... ${end - start}ms \\n`)\n }\n return { tSyncOnly, tSyncAsync }\n }\n}\n\nasync function measure(asyncFn) {\n const stack = new Stack\n const scopes = new Set\n const timer = new Timer\n const detail = new Map\n const hook = createHook({\n init(scope, type, parent, resource) {\n if (type === \'TIMERWRAP\') return\n scopes.add(scope)\n detail.set(scope, {\n type: type,\n offset: type === \'Timeout\' ? resource._idleTimeout : 0\n })\n },\n before(scope) {\n if (stack.is_not_empty) timer.ends(stack.peek())\n stack.push(scope)\n timer.starts(scope)\n },\n after() {\n timer.ends(stack.pop())\n }\n })\n\n // Force to create a new async scope by wrapping asyncFn in setTimeout,\n // st sync part of asyncFn() is a async op from async_hooks POV.\n // The extra async scope also take time to run which should not be count\n return await new Promise(r => {\n hook.enable()\n setTimeout(() => {\n asyncFn()\n .then(() => hook.disable())\n .then(() => r(timer.report(scopes, detail)))\n .catch(console.error)\n }, 1)\n })\n}\n测试
\n\n// arrange\nconst hang = (ms) => {\n const t0 = Date.now()\n while (Date.now() - t0 < ms) { }\n}\nconst asyncFunc = async () => {\n hang(16) // 16\n try {\n await new Promise(r => {\n hang(16) // 16\n setTimeout(() => {\n hang(16) // 16\n r()\n }, 100) // 100\n })\n hang(16) // 16\n } catch (e) { }\n hang(16) // 16\n}\n// act\nprocess.nextTick(() => hang(100)) // 100\nmeasure(asyncFunc).then(report => {\n // inspect\n const { tSyncOnly, tSyncAsync } = report\n console.log(`\n \xe2\x88\x91 Sync Ops = ${tSyncOnly}ms \\t (expected=${16 * 5})\n \xe2\x88\x91 Sync&Async Ops = ${tSyncAsync}ms \\t (expected=${16 * 5 + 100})\n `)\n}).catch(e => {\n console.error(e)\n})\n结果
\n\nasync scope 3 ... 38ms\nasync scope 14 ... 16ms\nasync scope 24 ... 0ms\nasync scope 17 ... 32ms\n\n \xe2\x88\x91 Sync Ops = 86ms (expected=80)\n \xe2\x88\x91 Sync&Async Ops = 187ms (expected=180)\n