【Node.js】Console.log…お前…ブロッキングメソッドやったんか…？

TL;DR

• process.stdout, process.stderr は所定の条件で書き込みがブロッキングになる
  • これらを利用している console.log, console.error も然り
• Worker Threadで実行すれば本体のイベントループをブロックせずに済む

ログが重い

AWS ECS上にNode.js(Express)でAPIサーバを立てているのだが、
どうもレスポンスが重いので、
重い箇所を調べるために、console.logを追加で埋め込んだら更に遅くなった。

いやーまさかね。

process I/Oの注意点

公式ドキュメントを読み漁って以下の記述にたどり着いた。

これによると process.stdout, process.stderr は次の動作をする:

• ファイルに書き込むとき→同期
• ターミナルに書き込むとき→Windowsだと非同期、POSIXだと同期
• パイプ→Windowsだと同期、POSIXだと非同期

ここでいう同期的実行というのは、○○Sync系のメソッドと同様で、
応答が返るまでイベントループが止まるというもの。
要は、asyncと違い、別の実行まで阻害するということだ。

これをWebAPIに適用した場合、
あるアクセスがログを記録している間、他のアクセスに関する処理が一切行えないということである。

console、お前だったのか。

解決方法

Worker Threadsを使って別のスレッドで実行すれば、メインスレッドはブロックされない。

とりあえずconsole.log版を例にあげる。
(以下の2ファイルを logAsync とかな名前のディレクトリにいれておく)

index.ts

import { Worker } from 'worker_threads';
import path from 'path';

const worker = new Worker(path.join(__dirname, 'worker'));

/**
 * ノンブロッキングでconsole.logを実行する
 * 注: 普通にconsole.logをすると、出力先がTTY(コンソールとか)の場合ブロッキングになる
 * https://nodejs.org/api/process.html#a-note-on-process-io
 * @param value ログオブジェクト
 */
export function logAsync(value: unknown): void {
  worker.postMessage(value);
}

worker.ts

import { parentPort } from 'worker_threads';

parentPort?.on('message', (value) => console.log(value));

注意点

別スレッドに渡すだけあって、 Worker.postMessage に渡せるオブジェクトには制限がある。
ただ、HTML structured clone alrotighmの拡張版というべきものが採用されていて、
思ったよりは色々転送できる。

書くと長くなるので詳しくは以下を参照されたい。

おわりに

Qiita, Zenn, StackOverflowあたりは検索したと思うんだけど、
これでつまづいている人を見つけられなかったので、今回記事にしてみた。

つまづいている人すら見つからないということは誰の役にも立たないかもしれない…