在公司搬砖给Node.js写C++插件的时候遇到了一个BUG：在为Node.js导出的C++类中，如果存储了uv_async_t对象，会让一些Node.js的async/await操作不能正常工作。套上async/await，代码执行到C++代码通过回调函数异步返回给JS数据之后，脚本就停止工作了。
C++部分的代码大致是这样的：
#include <nan.h>
#include <memory>
#include <thread>
#include <vector>
// simple wrapper for uv_async_t
class uvAsyncEvent
{
public:
uvAsyncEvent(void* context, uv_async_cb callback)
{
m_pAsyncHandle.reset(new uv_async_t());
m_pAsyncHandle->data = context;
uv_async_init(uv_default_loop(), m_pAsyncHandle.get(), callback);
}
~uvAsyncEvent()
{
}
void* GetContext() const
{
return m_pAsyncHandle->data;
}
void Notify()
{
uv_async_send(m_pAsyncHandle.get());
}
private:
struct Deleter
{
void operator()(uv_async_t* asyncEvent) const
{
if (asyncEvent)
{
uv_close((uv_handle_t*)asyncEvent, Deleter::uvCloseCallback);
}
}
static void uvCloseCallback(uv_handle_t* handle)
{
delete (uv_async_t*)handle;
}
};
std::unique_ptr<uv_async_t, Deleter> m_pAsyncHandle;
};
// a c++ class exported to Node.js which holds uv_async_t handles
class Hang
: public Nan::ObjectWrap
{
public:
static NAN_MODULE_INIT(Init)
{
v8::Local<v8::FunctionTemplate> tpl = Nan::New<v8::FunctionTemplate>(New);
tpl->SetClassName(Nan::New("Hang").ToLocalChecked());
tpl->InstanceTemplate()->SetInternalFieldCount(1);
Nan::SetPrototypeMethod(tpl, "start", Start);
Nan::SetPrototypeMethod(tpl, "stop", Stop);
Nan::SetPrototypeMethod(tpl, "setCallback", SetCallback);
constructor.Reset(Nan::GetFunction(tpl).ToLocalChecked());
Nan::Set(target, Nan::New("Hang").ToLocalChecked(), Nan::GetFunction(tpl).ToLocalChecked());
}
private:
Hang()
: m_pEvent(std::make_unique<uvAsyncEvent>(this, asyncCallback)) // async/await hangs
, m_bRunning(true)
{
}
public:
~Hang()
{
}
static NAN_METHOD(New)
{
if (info.IsConstructCall()) {
// Invoked as constructor: `new Hang(...)`
Hang* obj = new Hang();
obj->Wrap(info.This());
info.GetReturnValue().Set(info.This());
v8::Local<v8::Object> context = v8::Local<v8::Object>::Cast(info[0]);
}
else {
// Invoked as plain function `Hang(...)`, turn into construct call.
const int argc = 1;
v8::Local<v8::Value> argv[argc] = { info[0] };
v8::Local<v8::Function> cons = Nan::New(constructor);
v8::Local<v8::Object> result =
Nan::NewInstance(cons, argc, argv).ToLocalChecked();
info.GetReturnValue().Set(result);
}
}
static NAN_METHOD(SetCallback)
{
Hang* obj = ObjectWrap::Unwrap<Hang>(info.Holder());
if (!info[0]->IsFunction())
{
Nan::ThrowTypeError("arg 1 is not function");
return;
}
obj->m_evCallback.reset(new Nan::Callback(info[0].As<v8::Function>()));
}
static NAN_METHOD(Start)
{
Hang* obj = ObjectWrap::Unwrap<Hang>(info.Holder());
obj->m_bRunning = true;
struct ThreadRunner
{
ThreadRunner(Hang& h)
: m_obj(h)
{
}
// Run
void operator()()
{
while (m_obj.m_bRunning) {
std::this_thread::sleep_for(std::chrono::milliseconds(1000));
m_obj.m_pEvent->Notify();
}
}
private:
Hang& m_obj;
};
if (!obj->m_workThread)
{
obj->m_workThread = std::make_unique<std::thread>(ThreadRunner(*obj));
}
}
static NAN_METHOD(Stop)
{
Hang* obj = ObjectWrap::Unwrap<Hang>(info.Holder());
obj->m_bRunning = false;
if (obj->m_workThread)
{
obj->m_workThread->join();
obj->m_workThread.reset();
}
obj->m_pEvent.reset();
}
private:
static void asyncCallback(uv_async_t* handle)
{
Hang* pThis = (Hang*)handle->data;
Nan::HandleScope scope;
auto ret = Nan::New("async callback").ToLocalChecked();
v8::Local<v8::Value> argv[] = { ret };
Nan::Call(*pThis->m_evCallback, 1, argv);
}
private:
std::unique_ptr<uvAsyncEvent> m_pEvent;
std::unique_ptr<Nan::Callback> m_evCallback;
std::unique_ptr<std::thread> m_workThread;
bool m_bRunning;
private:
static Nan::Persistent<v8::Function> constructor;
};
Nan::Persistent<v8::Function> Hang::constructor;
// an asynchronous function for test
NAN_METHOD(testAsync)
{
class Worker : public Nan::AsyncWorker
{
public:
Worker(Nan::Callback* callbk)
: Nan::AsyncWorker(callbk)
{
}
void Execute() override
{
std::this_thread::sleep_for(std::chrono::milliseconds(100));
}
void HandleOKCallback() override
{
Nan::HandleScope scope;
int argc = 1;
std::unique_ptr<v8::Local<v8::Value>[]> argv(new v8::Local<v8::Value>[argc]());
argv[0] = Nan::New("async task result").ToLocalChecked();
Nan::Call(*callback, argc, argv.get());
}
};
Nan::Callback* callbk = new Nan::Callback(Nan::To<v8::Function>(info[0]).ToLocalChecked());
Worker* pWorker = new Worker(callbk);
Nan::AsyncQueueWorker(pWorker);
}
NAN_MODULE_INIT(InitAll)
{
Hang::Init(target);
Nan::SetMethod(target, "testAsync", testAsync);
}
NODE_MODULE(hang, InitAll)
用来测试的脚本：
const { Hang, testAsync } = require('./build/Release/hang');
const { EventEmitter } = require('events');
let h = new Hang();
// calling start method or not does not affect the problem
// h.start();
function doTestAsync() {
return new Promise((resolve, reject) => {
testAsync((data) => {
// This line of code got executed without any problems
// after 100ms of the function call(according to the C++ code)
console.log(data);
resolve(data);
});
});
}
function doSetTimeoutAsync() {
return new Promise((resolve, reject) => {
setTimeout(() => {
let data = 'timeout async';
console.log(data);
resolve(data);
}, 100)
});
}
// this is ok
//testAsync((data) => {
// console.log(data);
//});
async function testHang() {
let asyncRet = await doSetTimeoutAsync();
// no problem
console.log("after async call1");
let asyncRet2 = await doTestAsync();
// async/await operation blocks due to the creation of "hang"
// I paused the execution via the debugger, then continue,
// Dramatically this line gets executed
console.log("after async call2");
let asyncRet3 = await doTestAsync();
console.log("after async call3");
let asyncRet4 = await doTestAsync();
console.log("after async call4");
h.stop();
}
testHang();
背景和BUG表现
公司搬砖的项目里，要建立一个TCP长连接，用于与服务端之间通信和保持在线状态。通常情况下会单独启动一个线程用来维护连接，现在要把从服务端接收到的数据传给JS，一个很明显的思路是在工作线程里调用uv_async_send来通知主线程（能调用V8的API的线程）有数据传过来。
代码本身是简化后的模型。C++模块导出了一个Hang类和一个testAsync函数，Hang类对应的C++类管理了一个uv_async_t对象，testAsync函数使用了Nan::AsyncWorker用于测试Node.js的异步调用。
发生的问题是：直接通过命令行运行脚本，测试脚本会卡在调用doTestAsync之后，after async call2不会被输出出来。在vscode中启用调试模式时得到的结果也一样。程序的输出是这样的：
timeout async
after async call1
async task result
诡异的是，在vscode中把脚本暂停，脚本成功中断在了Node.js内部的代码里，然后继续运行，后面的输出居然输出了出来。然后脚本继续卡在第二次调用doTestAsync之后。如此暂停和继续运行，测试脚本居然能一路跑下去。
如果把断点停在testAsync提供的回调函数里，会发现程序走过resolve(data)之后就不能继续运行了。
把脚本本身改写成回调金字塔的样式，就像下面的代码一样，也是没有问题的。但是这样真的是太丑了，而且async/await是官方推崇的方式，总算能彻底解决回调金字塔地狱的问题，因为出现了这状况丫的还得改回去……
testAsync((data) => {
console.log(data);
console.log("after async call2");
testAsync((data) => {
console.log(data);
console.log("after async call3");
testAsync((data) => {
console.log(data);
console.log("after async call4");
});
});
});
尝试解决
首先用二分法找问题原因，逐个排查最近的修改，发现去掉了创建uv_async_t对象的代码，这个问题就不再出现了。
于是整理了下代码，写了个最小的可以必现这个问题的示例。信心满满地向Node.js提交了个issue，然后这个issue一小时后被项目管理者打入了nodejs/help的冷宫，而且没人回答我提出的问题。
既然没有人愿意回答我的问题，那就自己干！
不管怎么说先build个Debug版本的Node.js程序，Release版本经过优化，找错没有那么容易。签出代码库，按照vcbuild.bat的指示来构建，好了，Debug版的Node.js程序有了。因为ABI的问题，又手动建了个vcxproj项目把刚才的c++代码链接到了debug版生成出来的node.lib上。
然后开始调试。先找下Promise是在哪里实现的，Node.js中用JS写的实现都是放在lib目录下。在这个目录下搜索Promise字样，无果。然后在C++代码里继续搜，发现v8.h中声明了一个Promise类。Promise类里面声明了个Resolve方法。于是抱着试试看的心态在这个方法的实现（在deps/v8/src/api.cc）里加了断点。然后在vs的调试选项里面让Debug版的Node.js进程执行我们的测试脚本，脚本照样还是卡住了，api.cc里面的断点没有进去，看来找的Promise的实现的位置不对。
继续找Promise的实现，看到Promise类的声明里有个PromiseState枚举类型，应该是用来表示Promise对象当前的状态的，心想v8脚本引擎的内外应该都用同一种类型，用”查找所有引用”找了一下，原来v8脚本引擎内部还有个v8::internal::JSPromise类（在deps/v8/src/objects/js-promise.h里）。F12进去，看到了这样的代码，在deps/v8/src/objects.cc里面，这个应该是我们要找的Promise.resolve的实现了：
Handle<Object> JSPromise::Fulfill(Handle<JSPromise> promise,
Handle<Object> value) {
...
// 6. Set promise.[[PromiseState]] to "fulfilled".
promise->set_status(Promise::kFulfilled);
// 7. Return TriggerPromiseReactions(reactions, value).
return TriggerPromiseReactions(isolate, reactions, value,
PromiseReaction::kFulfill);
}
// static
MaybeHandle<Object> JSPromise::Resolve(Handle<JSPromise> promise,
Handle<Object> resolution) {
Isolate* const isolate = promise->GetIsolate();
isolate->RunPromiseHook(PromiseHookType::kResolve, promise,
isolate->factory()->undefined_value());
...
// 7. If Type(resolution) is not Object, then
if (!resolution->IsJSReceiver()) {
// a. Return FulfillPromise(promise, resolution).
return Fulfill(promise, resolution);
}
...
// 10. Let thenAction be then.[[Value]].
// 11. If IsCallable(thenAction) is false, then
if (!then_action->IsCallable()) {
// a. Return FulfillPromise(promise, resolution).
return Fulfill(promise, resolution);
}
// 12. Perform EnqueueJob("PromiseJobs", PromiseResolveThenableJob,
// «promise, resolution, thenAction»).
Handle<PromiseResolveThenableJobTask> task =
isolate->factory()->NewPromiseResolveThenableJobTask(
promise, Handle<JSReceiver>::cast(then_action),
Handle<JSReceiver>::cast(resolution), isolate->native_context());
if (isolate->debug()->is_active() && resolution->IsJSPromise()) {
// Mark the dependency of the new {promise} on the {resolution}.
Object::SetProperty(resolution,
isolate->factory()->promise_handled_by_symbol(),
promise, LanguageMode::kStrict)
.Check();
}
isolate->EnqueueMicrotask(task);
// 13. Return undefined.
return isolate->factory()->undefined_value();
}
在这个函数里加了断点，重新调试。发现在程序卡住之前，Node.js居然没有在JSPromise这里中断！甚至在after async call1输出之前，Node.js进程也没中断在刚才在objects.cc中加的断点上。
如果换一种调用JS脚本的方式：在shell模式下运行Node.js，输入命令require('./hang.js')调用脚本，在JSPromise里加的断点生效了，但是程序之后卡住的时候，仍然没进到加的断点上。
两种运行脚本的方式得到不同结果的原因，大概是在命令参数里直接运行脚本的时候，Node.js把脚本的JS代码包括Promise操作全都JIT掉了，JSPromise里面的那些代码根本没有用。
看来这个问题和Promise的实现是没有关系的。至于还有什么其它原因实在是百思不得其解。
转机
问题解决
这个问题拖了将近一周的时间，直到有一天想这个问题的时候拖了下控制台窗口，改变了下Node.js控制台窗口的大小。改变了窗口大小之后，await后面的语句居然被执行了！
期待的结果出现了，赶紧分析下到底发生了什么让结果是对的。再次打开Node.js项目里编译生成的node.sln，用我们的debug版的Node.js启动测试脚本，脚本毫无悬念地卡死。这时候在VS调试器里暂停node.exe的运行，看到主线程中断在了下面的位置：
可以看到Node.js调用了Windows的IOCP。一直等待的情况下，只有IOCP管理的HANDLE对应的IO操作完成或者用PostQueuedCompletionStatus直接向IOCP对象发消息，IOCP的等待操作才会退出。再看一下node.exe调用GetQueuedCompletionStatusEx传进去的超时时间是多少，现在这个状态下这个值是-1。所以说程序卡死的原因是一直在等待一个IOCP事件传过来。然而尝试修改前面的timeout数值，改成不是一直等待，重新编译代码，卡死的问题仍然存在。
在GetQueuedCompletionStatusEx的下一行加个断点，然后让node.exe继续跑下去。这之后拖一下控制台窗口，继续单步跟下去，可以看到IOCP消息对应的libuv消息（uv_req_t）类型是UV_SIGNAL_REQ。继续跟到循环结束走到下一轮循环，单步调试到uv_process_signal_req的时候（在uv_process_reqs里面），可以看到信号的编号是28。编号为28的信号是什么信号？查了下是SIGWINCH，在控制台窗口大小发生改变时，操作系统会向对应的进程发送这个信号。不管这么多，继续单步调试跑到下面signal_wrap.cc的代码时，代码走过wrap->MakeCallback这一行之后，await后面的JS代码要输出的东西输出到了屏幕上。
static void OnSignal(uv_signal_t* handle, int signum) {
SignalWrap* wrap = ContainerOf(&SignalWrap::handle_, handle);
Environment* env = wrap->env();
HandleScope handle_scope(env->isolate());
Context::Scope context_scope(env->context());
Local<Value> arg = Integer::New(env->isolate(), signum);
wrap->MakeCallback(env->onsignal_string(), 1, &arg);
}
所以这个MakeCallback到底做了什么？看代码可以知道SignalWrap也是向JS环境导出的一个类，在JS端的名字叫Signal。在node项目的lib目录下狂搜，找到了与SIGWINCH信号相关的几个处理函数，但是这些函数和执行当前要继续执行的JS代码都没有任何关系。所以可能是C++代码的问题？
换一种思路来找代码能正常运行的原因。既然控制台都有输出，在Windows下向控制台窗口输出，最终都会调用kernel32.dll导出的WriteConsole函数。又因为涉及到字符串的函数Windows都会提供分别处理char*和wchar_t*的两种函数，所以需要加两个断点，按Ctrl+B打开添加断点窗口，手动加上这两个断点：
{,,kernel32.dll}WriteConsoleA
{,,kernel32.dll}WriteConsoleW
在启用这两个断点调试的情况下去单步调试MakeCallback方法的实现，最终锁定到了这一行C++代码：
代码中断在env_->tick_callback_function()->Call(process, 0, nullptr).IsEmpty()这一行时，让代码继续运行，node进程就会立刻中断在kernel32.dll导出的WriteConsoleW函数上。看函数的名字tick_callback_function，这个应该就是用来执行等待运行的JS代码的相关的函数，也就是测试脚本里await之后的部分。
所以结论是：拖动控制台窗口能让async/await继续运行，完全是个副作用。原因只不过是Node.js要运行操作系统信号相关的处理函数的时候，顺带会把等待执行的JS代码拎过来也执行一下而已。鬼使神差地就让脚本按预期的方式工作了。至于为什么新建uv_async_t对象就会让Node.js陷入无限等待IOCP消息的状态，这个我实在是无力去追查。
SIGWINCH信号是如何在windows下模拟出来的
Windows本身是不支持SIGWINCH信号的，Node.js(libuv)用启动监听线程监听控制台窗口大小变化的方法模拟了这个信号。窗口大小变化的消息本身是用PostQueuedCompletionStatus直接向主线程IOCP发消息发过去的。要验证可以Ctrl+B手动加个断点{,,kernelbase.dll}PostQueuedCompletionStatus，然后拖动控制台窗口，程序就会中断在监听控制台窗口的线程里面。
解决办法
既然系统向Node.js进程发送SIGWINCH信号会迫使Node.js去运行下个事件循环需要执行的JS代码，那么解决方法也就出来了。
方法是：在测试脚本前面加个定时器，向当前Node.js进程不停地发送SIGWINCH信号，脚本就能继续跑下去直到结束：
setInterval(() => {
process.emit('SIGWINCH');
}, 100);
这个解决方法实在是过于草生（中日双语），我始终认为这是Node.js的BUG，应该在事件循环处于空闲的状态时就去处理等待执行的JS代码，然而官方不理，当然原因也可能是真的不好处理。
感想
- 二分法找BUG万岁。
- 带JIT的脚本引擎找问题是真难，因为JIT出来的汇编代码产出的调用堆栈和编译器生成出来的约定不一样。然后你就没办法看到调用JIT代码之前的堆栈发生了什么。
- 有些固有的BUG估计是没有人会理的，久而久之估计就成了feature。
后续
Node.js 8.x 10.x 12.x 在Windows/Linux上都有这个问题，Mac没条件试。