node.js - Node worker_threads console.log 出现在 postMessage 之后

Question

Node v10.16.3

我正在运行 worker_threads来自 Node 官方文档的示例。为了测试共享变量，我做了一些更改。这是一个例子

工作线程.js

const {
  Worker,
  isMainThread,
  parentPort,
  workerData
} = require("worker_threads");

let a = 10;

if (isMainThread) {
  module.exports = async function parseJSAsync(num) {
    return new Promise((resolve, reject) => {
      const worker = new Worker(__filename, {
        workerData: num
      });
      worker.on("message", resolve);
      worker.on("error", reject);
      worker.on("exit", code => {
        if (code !== 0)
          reject(new Error(`Worker stopped with exit code ${code}`));
      });

      for (let i = 0; i < num; i++) {
        console.log("master: ", a);
        a++;
      }
    });
  };
} else {
  const num = workerData;
  let result = 1;
  for (let i = 1; i < num; i++) {
    console.log("worker: ", a);
    a--;
    result = result * i;
  }
  parentPort.postMessage(result);
}

并且有一个用于测试此示例的脚本:

const calculateFactorial = require("./work-thread");

calculateFactorial(10).then(res => console.log("res", res));

有一个 a主线程和工作线程都可以访问。
当我运行这段代码时，输​​出是

master:  10
master:  11
master:  12
master:  13
master:  14
master:  15
master:  16
master:  17
master:  18
master:  19
worker:  10
res 362880
worker:  9
worker:  8
worker:  7
worker:  6
worker:  5
worker:  4
worker:  3
worker:  2

我想知道为什么worker的postMessage早于worker的console.log

Answer 1

看起来日志记录依赖于主线程，主线程被 for 循环阻塞，直到它完成。来自worker的日志似乎在worker中调用console.log时被缓冲，但直到主线程被解除阻塞才真正写出。所以工作是并行完成的，但不是日志记录。我还没有找到这方面的引用，但可以通过运行依赖于时间的示例来验证:

const {
  Worker,
  isMainThread
} = require('worker_threads');

if (isMainThread) {
  console.log(`start time: ${Date.now()}`);
  const worker = new Worker(__filename);

  worker.on('exit', (code) => {
    console.log(`exited with code [${code}]`);
  });

  worker.on('error', (err) => {
    console.log(err);
  });

  // Block main thread for 10 seconds
  const start = new Date();
  while (true) {
    const now = new Date();
    if (now.getTime() - start.getTime() > 10000) {
      console.log('brook loop');
      break;
    }
  }

  // Stop worker after another 10 seconds
  setTimeout(() => worker.terminate(), 10000);
} else {
  setInterval(() => console.log(Date.now()), 1000);
}

下面的输出(注释了一些关于时间的评论)

start time: 1600900685482 // written to console immediately
brook loop // written to console 10s later
1600900686512 // these 10 lines are written all at one as soon as the loop is broken. Note that even though they are written at once, the times are all 1 second apart.
1600900687515
1600900688517
1600900689518
1600900690519
1600900691520
1600900692524
1600900693525
1600900694526
1600900695527
1600900696533 // after dumping the backlog of log lines from while the main thread was blocked, new lines are now written every 1 second
1600900697536
1600900698539
1600900699540
1600900700544
1600900701550
1600900702550
1600900703556
1600900704558
exited with code [1]