TypeScript异步函数内外计时差异过大的原因排查

相关代码 #

private async waitForLoad(timeout: number) {
  console.time("Inside WFL");
  let count = 0;

  while (this.getSignedIn() && !auth.currentUser) {
    await this.delay(10);
    count = count + 10;
    if (count >= timeout) {
      break;
    }
  }
  console.timeEnd("Inside WFL");
}

public async getToken(timeout: number): Promise<string> {
  console.time("Outside WFL");
  await this.waitForLoad(timeout);
  console.timeEnd("Outside WFL");

  if (auth.currentUser) {
    const token = await auth.currentUser.getIdToken();
    return token;
  } else {
    console.log("Auth: tried to get token on null user");
    throw new Error("Not signed in");
  }
}

控制台输出 #

Inside WFL: 0.112060546875 ms
Outside WFL: 100.983154296875 ms

问题 #

为何这两个计时结果差异如此巨大？

原因分析 #

核心问题出在console.time的计时范围和异步函数的执行调度逻辑上：

1. Inside WFL的计时未覆盖异步等待时间
   console.time("Inside WFL")放在waitForLoad函数开头，但函数执行到第一个await this.delay(10)时会暂停，跳出当前同步调用栈。此时console.timeEnd要等到所有循环内的异步延迟执行完毕才会触发，但这个计时仅统计了进入函数到首次await前的同步代码，以及循环结束后的收尾同步代码，完全漏掉了所有await delay(10)的等待时间。

2. Outside WFL的计时是waitForLoad的完整执行时间
   getToken中的console.time包裹了整个await waitForLoad(timeout)的过程，包含了waitForLoad内部所有同步代码+异步延迟的等待时间。从输出的100ms左右可以推断，循环总共执行了10次delay(10)，这部分时间全部被Outside WFL统计，却没被Inside WFL计入。

3. 异步函数的执行机制验证
   当waitForLoad遇到await时，会立即返回一个pending状态的Promise给getToken，getToken的await会等待该Promise完成。而waitForLoad内部的计时仅覆盖同步阶段，异步等待的时间都不在其统计范围内，这就是两个计时结果差距悬殊的根本原因。

简单总结：Inside WFL只测了同步代码耗时，Outside WFL测的是整个异步函数从调用到完成的全量耗时，两者的差异就是被漏掉的所有异步延迟等待的总时间。

内容的提问来源于stack exchange，提问作者Nick Schrock