名前の末尾の四文字が事故を分ける

一言でいうと

crypto.pbkdf2とcrypto.pbkdf2Syncは、同じ計算を同じ時間だけ行います。違うのはどこで動くかだけで、その違いが「このリクエストだけ遅い」と「全部が遅い」を分けます。そして、非同期だからといって、すべてが同じ場所にいるわけでもありません。

なぜ必要なのか

「非同期に変えればいい」という言い方は、ひとまとめにしすぎです。実際には3つの場所があり、3つの性質はそれぞれ違います。

1つ目は、イベントループ上で動く仕事です。JSON.parse、正規表現、大きな配列のソート、そして名前がSyncで終わるすべてのものがここにあります。これらの仕事は、動いている間、そのプロセスのほかのすべてを止めます。

2つ目は、libuvスレッドプールです。ファイル読み取りと圧縮、非同期の暗号演算がここに送られます。ループは自由ですが、枠が決まっています。 デフォルトが4枠なので、重い仕事を5つ同時に送ると、5つ目は前の1つが終わるまで開始すらできません。

3つ目は、カーネルです。ソケットの読み書きとdns.resolve*()がここです。OSが「準備ができた」と知らせるまで、ループはただ待ちます。スレッドもCPUも使いません。

この3つの場所を区別できないと、妙なことが起きます。たとえば画像圧縮を非同期に変えてループは救えたのに、その後でファイル読み取りが遅くなることがあります。2つが同じ4枠を分け合っているからです。コードだけ見ると、2つの機能には何の関係もありません。

どう動くのか

どのAPIがスレッドプールを使うかは、暗記するものではなく、ドキュメントに書かれています。NodeのコマンドラインオプションのドキュメントにあるUV_THREADPOOL_SIZEの節が、一覧を直接書いています。ファイル監視と明示的な同期関数を除くすべてのfs API、crypto.pbkdf2()・crypto.scrypt()・crypto.randomBytes()・crypto.randomFill()・crypto.generateKeyPair()のような非同期の暗号API、dns.lookup()、そして明示的な同期版を除くすべてのzlib APIです。同じドキュメントがデフォルトのサイズを4と書き、libuv側のドキュメントは絶対的な上限を1024と書いています(libuvスレッドプール)。

dns.lookupとdns.resolve4が分かれるところが、この一覧でいちばん紛らわしい点です。どちらも名前をアドレスに変えますが、前者はOSのgetaddrinfo(3)をスレッドプールで呼び、後者はネットワークに直接問い合わせます。NodeのDNSドキュメントは後者について、「このネットワーク通信は常に非同期で行われ、libuvのスレッドプールは使わない」と明記しています。そのため、名前の解決が多いサービスでファイル読み取りが遅くなることが、実際に起こります。

枠が4つだという事実は、測るとすぐに見えます。同じ重さの非同期の仕事を4つ送ると4つがほぼ同じ時刻に終わり、8つ送ると2つの塊に分かれます。ラボイメージのNode 22.11.0でCPU 2コアで測ると、次のようになります。

4개:  298 301 302 307 ms                          — 함께 끝난다
8개:  315 317 321 325 | 700 703 703 704 ms        — 뒤 네 개는 한 바퀴를 기다린다

では、枠を増やせばいいのでしょうか。UV_THREADPOOL_SIZE=8で測り直すと、8つすべてが710ms前後で終わります。波は消えましたが、全体が終わる時刻は変わりません。 増えたのは同時に開始できる仕事の数であり、計算してくれるCPUではないからです。同じドキュメントが添えている注意も重要です。この値をプログラムの中でprocess.envによって変更することは保証されていません。スレッドプールは、ユーザーコードが動くずっと前に作られるからです。

現場での姿

最もよくあるのは、非同期版がそもそもない仕事です。JSON.parseが代表的です。ファイルをfs.readFileで非同期に読んでも、その文字列をオブジェクトに変える仕事はループの上で行われます。Node 22.11.0で12.9MBのJSONをパースしてみると76msかかり、その間ループは58ms止まりました。移す先がないので、残る選択肢は本文のサイズを制限することだけです。リクエスト本文の上限がそのままレイテンシバジェットになる理由が、ここにあります。

2つ目は名前の末尾の4文字です。同じイメージで8MBをzlib.gzipSyncで圧縮するとループが183ms止まり、zlib.gzipで圧縮すると9msです。仕事そのものは、それぞれ178msと219msで似ています。コードレビューでSyncを探すことがパフォーマンス改善の最初の一手である理由が、この数字にあります。特に、起動時に設定ファイルを読むreadFileSyncは問題なく、リクエスト処理経路のreadFileSyncは事故になるという点です。同じ関数でもどこで呼ぶかが判断を変えます。

次のラボですること

公式ドキュメントの一覧を表に移し、その表が正しいかを自分で測って確かめます。同じ計算を同期と非同期で1回ずつ動かしてループの遅延を測り、非同期版がないJSON.parseで移す先のない仕事を確認し、同じ仕事8つを送ってスレッドプールの枠を数えます。UV_THREADPOOL_SIZEを上げると波が消えることと、全体の時間が変わらないことを一緒に測り、最後にzlibに同じ方法を適用します。