[译]Node.js: 快捷的async函数会如何阻塞事件循环，使I/O饥饿？

原文链接

背景

一个典型的Node.js应用基本上就是一个各类的事件响应执行的callback集合:一个接入的connection, I/O完成，timeout到期，Promise决议等等。这里有单个主线程（事件循环）执行所有的callback。因为其他正在pending的callback的在等待被执行，因此这些callback应该尽快的完成。这是一个Node.js已知且具有挑战性的局限，这个文档中做出了很好的解释。

我最近在工作中偶然发现了一个真实的事件循环阻止场景。当我尝试去修复问题时，我意识到我对事件循环的行为了解的非常少。一开始得到这样的认知，让我和我分享的一些开发小伙伴们非常惊讶。我认为重要的是，很多Node.js开发者也会有相同的认知，这促使我写了这篇文章。

关于这个主题已经存在了很多有价值的信息，但是我花了一些时间才找到我想要问的特定问题的答案。我将尽全力分享我遇到的各种问题和答案。我找到了很多很棒的文章，一些有趣的实验以及研究。

首先，让我们阻塞事件循环！

注意:

你可以通过clone:https://github.com/michael-go/node-async-block来调试这些代码。

所以，让我们先从一个简单的Express服务开始:

const express = require('express');

const PID = process.pid;

function log(msg) {
  console.log(`[${PID}]` ,new Date(), msg);
}

const app = express();

app.get('/healthcheck', function healthcheck(req, res) {
  log('they check my health');
  res.send('all good!\n')
});

const PORT = process.env.PORT || 1337;
let server = app.listen(PORT, () => log('server listening on :' + PORT));

现在让我们添加一个讨厌的事件循环阻止接口:

const crypto = require('crypto');

function randomString() {
  return crypto.randomBytes(100).toString('hex');
}

app.get('/compute-sync', function computeSync(req, res) {
  log('computing sync!');
  const hash = crypto.createHash('sha256');
  for (let i=0; i < 10e6; i++) {
    hash.update(randomString())
  }
  res.send(hash.digest('hex') + '\n');
});

所以我们期望，在/compute-sync执行的过程中，到/healthcheck的请求讲变慢。我们可以使用此bash单行代码来探测/healthcheck:

while true; do date && curl -m 5 http://localhost:1337/healthcheck && echo; sleep 1; done

它将每秒探测/healthcheck，如果5秒内没有响应就会超时。 让我们来试一下:

我们调用/compute-sync瞬间，health-checks开始超时，而且没有任何一个成功。注意Node.js进程的CPU占用率达到了100%。

43.2秒后计算结束，8个pending状态的/healthcheck请求完成，同时服务再次是可以响应的了。 这个情况非常糟糕，一个糟糕的请求完成阻塞了服务。 After 43.2 seconds the computation is over, 8 pending /healthcheck requests go through and the server is responsive again.有了单线程事件循环的知识，很明显为什么/compute-sync的代码阻塞了其他所有的请求:在这个请求完成之前，它不会归还事件循环调度器的控制权，所以这里/healthcheck的处理函数没有被执行的机会。

让我们不要阻塞它！

让我们添加一个新的接口/compute-async,这里我们将通过在每次计算步骤（太多的上下文切换？）之后，暂停并归还事件循环的控制权来划分长时间阻塞的循环...我们会稍后进行优化，而且每次N次迭代只暂停一次，不过让我们先从一个简单的例子开始:

app.get('/compute-async', async function computeAsync(req, res) {
  log('computing async!');

  const hash = crypto.createHash('sha256');

  const asyncUpdate = async () => hash.update(randomString());

  for (let i = 0; i < 10e6; i++) {
    await asyncUpdate();
  }
  res.send(hash.digest('hex') + '\n');
});

让我们试一下: ? hmm ….它仍然阻塞了事件循环？

这里发生了什么？这里Node.js优化了我们对async/await的使用吗？它花费更多的秒数去完成，所以看起来不是这样...如果异步实际上确实受到影响，则火焰图会给出提示。我们会可以使用这个很cool的项目去快速生产火焰图:

首先，运行/compute-sync时捕获的火焰图：

我们可以看到，当100%同步时，/compute-sync调用栈包含了express handler的调用栈 现在，
现在，运行/compute-async时捕获的火焰图：

运行在V8上下文的RunMicrotask & AsyncFunctionAwaitResolveClosure函数让另外一边的/compute-async火焰图看起来非常不一样，所以，不...看起来不是async/await被优化了。

在深入研究之前，让我们尝试一下，我们程序员有时会做的最后一件绝望的事:添加一个sleep调用。

让我们运行它:

最后，这个服务在繁重计算的期间保留了响应能力 ? 。不幸的是，这个解决方案的代价非常高:我们可以看到CPU的使用率大约10%，因此看来它在计算上的工作还不够努力，实际上这要花很长时间才能完成（没有足够的耐心才能看到它的发生?）。仅仅通过降低迭代的次数，从10⁷ 到10⁵，它在2:23分钟之后才会完成！(如果你想知道，传递1取代0作为延迟参数到setTimeout没有什么不同 — 稍后会详细的讲到)，

这就提出了几个问题： 为什么在不调用setTimeout()的情况下，async代码被阻塞了？ 为什么setTimeout()增加了如此庞大的性能开销？ 我们如何能在没有任何副作用的情况下不阻塞我们的计算？

事件循环阶段

当我身上发生了一些相似的事情，我求助Google去寻求帮助。搜索一些类似“node async block event loop”的东西，其中有一个搜索结果是Node.js官方的指南,它真的让我大开眼界。

它解释了事件循环不是我想象中的调度神器，而是一个相当简单的循环，其中包含多个阶段。这是从指南复制而来的漂亮的主要阶段的ASCII图：

(后来我发现这个循环在libuv中很好地实现了，其功能如图所示: github.com/libuv/libuv…) 这个指南解释了不同阶段的差异，并给出了以下概述：

这句话开始回答我们的问题：

这（依稀）表明当一个callback让另外一个会在同一个阶段被处理的callback入队了，然后它会在进入下一个阶段之前被处理。只有在poll阶段，Node.js才会为新的请求检查网络socket。所以这意味着我们在/compute-async中所做的事情实际上在事件循环离开一个确定的阶段时被阻止，这样就永远不会循环通过轮询阶段甚至不会收到/ healthcheck请求吗？ 我们需要更加深入去获取更好的答案，不过为什么setTimeout()有作用现在已经很清楚了:每次我们将一个timer callback入队，并且当前阶段的这个队列已经为空，事件循环必须遍历所有阶段才能到达“计时器”阶段，途中经过轮询阶段，并处理未决的网络请求。

? 微任务(Micro-Tasks)

我们都知道在/compute-async中使用async/await是一个Promise的同步语法糖，所以实际发生的是，我们每一个循环迭代中，创建Promise去计算哈希,而且当Promise被resolve后，我们的循环将进行以一次迭代。上面提到的官方指南没有说明在事件循环阶段如何处理Promise，但是我们的实验表明Promise的callback和已经resolve的callback都在没有经过事件循环poll阶段的情况下被运行了。

通过更多的Google，我发现了Deepal Jayasekara撰写的关于事件循环，更详细且写得更好的5条系列文章，其中还包含事件循环处理Promises相关的信息?。

它包含了这张有用的图:

圆圈周围的方框表示我们之前看到的不同阶段的队列，而中间那两个方框表示了在从一个阶段进入另一个阶段之前，需要被消费完的特殊队列。next tick queue处理通过nextTick()注册的callback,而Other Micro Tasks queue就是我们关于Promises疑问的答案。

在我们的情况中，如果一个被resolve的Promise创建了另一个Promise, 这个Promise会在进行下一个阶段前的同一阶段被处理吗？答案，正如我们所说，是肯定的！我们可以在V8源码看到这是如何发生的.这个连接指向了RunMicrotask()的实现代码。以下是相关代码行的实现片段:

TF_BUILTIN(RunMicrotasks, InternalBuiltinsAssembler) {
  ...
  Label init_queue_loop(this);
  Goto(&init_queue_loop);
  BIND(&init_queue_loop);
  {
    TVARIABLE(IntPtrT, index, IntPtrConstant(0));
    Label loop(this, &index), loop_next(this);

    TNode<IntPtrT> num_tasks = GetPendingMicrotaskCount(microtask_queue);
    ReturnIf(IntPtrEqual(num_tasks, IntPtrConstant(0)), UndefinedConstant());
    
    ...

    Goto(&loop);
    BIND(&loop);
    {
      ...
      index = IntPtrAdd(index.value(), IntPtrConstant(1));
      ...
      BIND(&is_callable);
      {
        ...
        Node* const result = CallJS(...);
        ...
        Goto(&loop_next);
      }

      BIND(&is_callback);
      {
        ...
        Node* const result =
            CallRuntime(Runtime::kRunMicrotaskCallback, ...);
        Goto(&loop_next);
      }

      BIND(&is_promise_resolve_thenable_job);
      {
        ...
        Node* const result = CallBuiltin(Builtins::kPromiseResolveThenableJob, ...);
        ...
        Goto(&loop_next);
      }

      BIND(&is_promise_fulfill_reaction_job);
      {
        ...
        Node* const result = CallBuiltin(Builtins::kPromiseFulfillReactionJob, ...);
        ...
        Goto(&loop_next);
      }

      BIND(&is_promise_reject_reaction_job);
      {
        ...
        Node* const result = CallBuiltin(Builtins::kPromiseRejectReactionJob, ...);
        ...
        Goto(&loop_next);
      }

      ...
      BIND(&loop_next);  // 这里是62行
      Branch(IntPtrLessThan(index.value(), num_tasks), &loop, &init_queue_loop);
    }
  }
}

这段C语言的代码，通过神奇的底层Goto()和Branch()函数和宏运行循环，看起来很奇怪。因为它是用V8的CodeStubAssembly(字节码)编写的，是“一个与平台无关的自定义汇编器，它提供低级基元作为对汇编的精简抽象”。

在核心部分我们可以看到，这里有一个名为init_queue_loop的外层循环和一个名为loop的内层循环。外层循环检查实际pending状态的微任务数目，而内层循环一个接一个的处理所有的任务。而且一旦完成，看到上面代码的第62行，它迭代了外层循环，这再次检查了实际pending状态的微任务数目，只有在没有任何任务被添加时，函数才会退return。

如果你了解在每一个事件循环阶段，微任务是如何处理的，我推荐关注Deepal Jayasekara的另一篇好文: (b.t.w, 记得我们为/compute-async创建的火焰图吗？如果你滑上去再看一遍，你就会理解调用栈中的RunMicrotasks())。同时注意，Micro-Tasks(微任务)是V8的东西，所以它也和Chrome相关，这里用同样的方式处理Promises — 不通过浏览器事件循环的自旋。

nextTick()不会tick

Node.js指南说:

这次文字非常清楚，因此我将为您保留另一张终端屏幕截图，但是您可以通过以下方法执行GET /compute-with-next-tick
github.com/michael-go/….

nextTick队列在这里被处理:
github.com/nodejs/node…

function _tickCallback() {
 ...
  do {
    while (tock = queue.shift()) {
      ...
      Reflect.apply(callback, undefined, tock.args);
      ...
    }
    runMicrotasks();
  } while (!queue.isEmpty() || emitPromiseRejectionWarnings());
  ...
}

这里很清晰，如果callback调用了另一个process.nextTick(),下一个callback将在同一个循环中被处理，并且只有在队列为空的时候才会退出。

setImmediate()来拯救吗？

所以, Promises很坑, Timers更坑 — 我们还能做什么? (?强行翻译原文:So, Promises are red, Timers are blue — what else can we do?)

看到上面的图，都提到了在check阶段被处理的setImmediate()队列，而在poll阶段之后，Node.js官方指南还说:

听起来不错，但最有希望的引用是：

你记得当我们使用setTimeout()时，该进程大部分是空闲的（即等待），使用了大约10％的CPU吗？ 让我们看看setImmediate()是否可以解决此问题:

app.get('/compute-with-set-immediate', async function computeWSetImmediate(req, res) {
  log('computing async with setImmidiate!');

  function setImmediatePromise() {
    return new Promise((resolve) => {
      setImmediate(() => resolve());
    });
  }

  const hash = crypto.createHash('sha256');
  for (let i = 0; i < 10e6; i++) {
    hash.update(randomString());
    await setImmediatePromise()
  }
  res.send(hash.digest('hex') + '\n');
});

Yay! 它没有阻塞服务，而且CPU使用率处于100%?! 让我们看看它花了多少时间完成调用:

好，很好 它在1:07分钟内完成，比/compute-sync大约长50％，比/compute-async大约长34％ — 但是它很有用，与/compute-with-set-timeout不同。鉴于这是一个玩具示例，我们在10⁷次小迭代中的每一次中都使用setImmediate()，这很可能导致10⁷次完整事件循环自旋，这种降速是可以理解的

那么在check阶段的上下中，setImmediate()的callback不会被在同一个阶段被处理吗？实际上，Node.js文档明确指出:
nodejs.org/api/timers.…:

当把setImmediate()和process.nextTick()进行比较，Node.js指南这样说:

已经被代码引用宠坏了的你们，请不要失望，我相信这是执行setImmediate()回调的实际代码:
github.com/nodejs/node…

b.t.w: Deepala系列的第3部分提到了一个很棒的事实:
(jsblog.insiderattack.net/promises-ne…, Bluebird, 一个很受欢迎的非原生Promise库也使用setImmediate()去调度Promise的`callbacks.

思想总结

(差不多，关于setTimeout()的加餐部分如下) 所以，setImmediate()看起来是一个划分同步代码长时间运行的解决方案。但是它不是总是简单的运行而且正确的运行。这里setImmediate()的生成有着明显的开销，pending状态下的请求越多，长时间运行的任务完成的时间越长 — 所以过多划分你的代码是有问题的，而且划分的太细会长时间阻塞时间循环。在某些情况中，阻塞代码并不是像我们示例中那样一个简单的循环。比如递归遍历一个复杂的数据结构，要找到合适的位置和使用条件变得更加棘手。

对于一些情况，一个可行的方案是追踪在调用setImmediate()前的阻塞耗时。这个片段只会在至少在上一个setImmediate()调用后10ms才会再次调用setImmediate()。

...
let blockingSince = Date.now()

async function crazyRecursion() {
  ...
  if (blockingSince + 10 > Date.now()) {
    await setImmediatePromise();
    blockingSince = Date.now();
  }
  ...
} 

其他情况如第三方库，你无法完全把控(底层的代码)可能导致阻塞 - 甚至像JSON.parse()内建函数都可能导致阻塞。 一个更极端的解决方案是把具有潜在阻塞可能的代码放到一个不同的服务(非Node.js)上，或者通过子进程(通过像tiny-worker的库)或者通过诸如webworker-threads或内置（仍处于试验阶段）之类的程序包的实际线程:https://nodejs.org/api/worker_threads.htm. 在多数情况下，这是一个正确的解决方案，但是所有这些分离的解决方案都带有来回传递序列化数据的障碍，因为分离后的代码无法访问JS主线程（唯一线程）的上下文。

所以这些方案所面临的普遍挑战是避免阻塞的职责是在每一个开发人员手中，而不是操作系统，像例如大多数线程语言或run-time VM的职责,如在Erlang中,不仅很难确保所有开发人员都始终意识到这一点，而且很多时候通过代码显式处理也不是最佳选择，因为代码缺乏上下文以及其他未决例程和IO所发生情况的可见性。

Node.js启用的高吞吐量（如果使用不当的话）可能会由于单个阻塞操作而导致许多待处理的请求在线等待。尽可能快地向load-balancer(负载均衡器)发出信号，表明服务器有很长的滞后请求列表, 同时使请求可以定向到不同节点，你也可以在健康检查接口中(这在实际的阻塞中不会有帮助...)使用如toobusy-js的库,这也是and make it route requests to different nodes, you can try using packages such as toobusy-js in your health-check endpoints (this won’t help during the actual blocking…).通过像blocked-at这样的库或者solutions like N|Solid和New-Relic这样的解决方案去监控时间循环在运行时也很重要。

加餐: 为什么setTimeout(0)的0不是真的0？

我真的很好奇为什么setTimeout(0)使进程90％处于空闲状态而不是吃力地进行计算。空闲的CPU可能意味着Node.js的主线程运行了一个系统调用，导致它的执行(i.e. sleep)被长时间挂起，直到内核重新调用让它继续执行，在setTimeout()有一些提示。
阅读libuv处理定时器相关的源码，看起来真正的sleep发生在uv__io_poll(),通过timeout参数传递作为poll()系统调用的一部分:
https://github.com/libuv/libuv/blob/v1.22.0/src/unix/posix-poll.c#L188.
poll()的主页说到:

所以，除非timeout确认是0，否则进程将进行休眠。我们怀疑尽管传递一个0值给setTimeout(),而实际传递给poll()的timeout值更高。我们可以尝试通过gdb调试node自身来验证一下。
我们可以通过dprintf命令来追踪uv__io_poll()的所有调用情况: So, unless the timeout is exactly 0, the process will sleep. We suspect that despite passing 0 to setTimeout() the actual timeout passed to poll() is higher. We can try to validate that by debugging node itself via gdb.

dprintf uv__io_poll, "uv__io_poll(timeout=%d)\n", timeout

让我们也在每一次调用轨迹上打印当前的时间:

dprintf uv__io_poll, "%d: uv__io_poll(timeout=%d)\n", loop->time, timeout

当我们的服务启动,uv__io_poll()传入timeout等于-1被调用,这意味“无尽的超时时间” — 因为它跟HTTP请求预期的等待时间没有关系。现在，让我们请求GET /compute-with-set-timeout接口:

正如我们所见,timeout有时为1，也为0，通常在两个连续的调用之间至少间隔1毫秒。而用同样的方式调试GET /compute-with-set-immediate将总是显示0。
对于CPU来说,1毫秒是一个相当长的时间。/compute-sync那样紧凑的循环在43秒内中完成来10⁷次迭代，这意味着它每次毫秒做来大约233次随机的哈希计算，每次迭代等待1毫秒意味着等待10,000毫秒 = 2:45小时!
让我们尝试理解为什么timeout传递给uv__io_poll不是0。timeout参数在uv_backend_timeout()计算然后作为参数传递给to uv__io_poll(),可以在主页的时间循环中看到:
github.com/libuv/libuv…. 对于一些情况(如一个pending状态的处理和请求)uv_backend_timeout()返回0，否则它返回uv__next_timeout()的结果，它从定时器堆(timer-heap)选取最近的timeout并且返回保留的时间作为它的过期时间。
uv_timer_start()是用于添加“timeouts”到定时器堆(timer-heap)。
这个在很多被调用，所以我们可以尝试设置一个断点去更好的定位，我们场景中传递0值的调用者。在断点处在GDB中运行info stack命令可以得到：

#0  uv_timer_start (handle=0x2504cb0, cb=0x97c610 <node::(anonymous  namespace)::TimerWrap::OnTimeout(uv_timer_s*)>, timeout=0x1, repeat=0x0) at ../deps/uv/src/timer.c:77
#1  0x000000000097c540 in node::(anonymous namespace)::TimerWrap::Start(v8::FunctionCallbackInfo<v8::Value> const&) ()
#2  0x0000000000b5996f in v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<false>(v8::internal::Isolate*, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, v8::internal::BuiltinArguments) ()
#3  0x0000000000b5a4d9 in v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) ()
#4  0x00003cc0e2fdc01d in ?? ()
#5  0x00003cc0e3005ada in ?? ()
#6  0x00003cc0e2fdbf81 in ?? ()
#7  0x00007fffffff8140 in ?? ()
#8  0x0000000000000006 in ?? ()
... (more nonsense addresses)

TimerWrap::Start仅仅uv_timer_start()的一个简易封装，并且这些无法识别的调用栈地址表明我们实际寻找的代码可能是Javascript实现的。通过再次寻找TimerWrap:Start在Node中的源码或者通过JS层的调试器，简单的“stepping into”(向里一步)进入到setTimeout()的实现,我们可以快速定位到Timeout的构造器在
github.com/nodejs/node…:

function Timeout(callback, after, args, isRepeat, isUnrefed) {
  after *= 1; // coalesce to number or NaN
  if (!(after >= 1 && after <= TIMEOUT_MAX)) {
    if (after > TIMEOUT_MAX) {
      process.emitWarning(`${after} does not fit into a 32-bit signed integer. Timeout duration was set to 1.',
                          'TimeoutOverflowWarning'`);
    }
    after = 1; // schedule on next tick, follows browser behavior
  }
  ...
}

最终，我们能在这里?看到timeout由0合并为1?. 希望你觉得本文对你有帮忙。感谢阅读。(PS:翻译不易,点个赞呗!!!)

参考资料

• nodejs.org/en/docs/gui…
• jsblog.insiderattack.net/event-loop-… (5 article series)
• jsblog.insiderattack.net/crossing-th…
• github.com/nodejs/node
• github.com/libuv/libuv (also vendored in nodejs/node)
• github.com/v8/v8 (also vendored in nodejs/node)

更多相关资料:

• javabeginnerstutorial.com/node-js/eve…* node-js/
• stackoverflow.com/questions/3…
• stackoverflow.com/questions/4…
• stackoverflow.com/questions/5…
• voidcanvas.com/setimmediat…
• webapplog.com/event-loop/
• dtrace.org/blogs/brend…
• developer.mozilla.org/en-US/docs/…
• jakearchibald.com/2015/tasks-… — browsers
• www.codementor.io/simenli/dem…
• blog.risingstack.com/node-js-at-…
• gist.github.com/othiym23/61…
• humanwhocodes.com/blog/2013/0…
• runnable.com/blog/get-yo…
• www.dynatrace.com/news/blog/a…
• medium.com/airbnb-engi…