Node.js の execSync に関する一点の問題

久しぶりに水文を書きました。昨日、Node.js の execSync 関数の特異な動作に関する問題を調べる手伝いをしたのですが、とても興味深かったので、ざっと記録しておきます。

背景#

まず、兄貴からスクリーンショットをもらいました。

問題のスクリーンショット

基本的な問題は、Node.js で execSync 関数を使って ps -Af | grep -q -E -c "\\-\\-user-data-dir=\\.+App" というコマンドを実行する際に、Node.js が時々エラーを報告するということです。具体的なスタックトレースは以下の通りです。

Uncaught Error: Command failed: ps -Af | grep -q -E -c "\-\-user-data-dir=\.+App"
    at checkExecSyncError (child_process.js:616:11)
    at Object.execSync (child_process.js:652:15) {
  status: 1,
  signal: null,
  output: [ null, <Buffer >, <Buffer > ],
  pid: 89073,
  stdout: <Buffer >,
  stderr: <Buffer >
}

しかし、同じコマンドをターミナルで実行すると、そのような現象は見られません。ですので、この問題は少し厄介です。

分析#

まず、Node.js のドキュメントにおける execSync の説明を見てみましょう。

child_process.execSync () メソッドは、一般的に child_process.exec () と同じですが、メソッドは子プロセスが完全に終了するまで戻りません。タイムアウトが発生し、killSignal が送信されると、メソッドはプロセスが完全に終了するまで戻りません。子プロセスが SIGTERM シグナルを捕捉して処理し、終了しない場合、親プロセスは子プロセスが終了するまで待機します。
プロセスがタイムアウトするか、非ゼロの終了コードを持つ場合、このメソッドは例外をスローします。Error オブジェクトには child_process.spawnSync () からの全結果が含まれます。
この関数に未処理のユーザー入力を渡さないでください。シェルメタキャラクターを含む入力は、任意のコマンド実行を引き起こす可能性があります。

要するに、この関数は子プロセスを通じてコマンドを実行し、コマンドの実行がタイムアウトするまで待機します。問題ありません。それでは、上記のエラースタックと execSync の実装コードを見てみましょう。

function execSync(command, options) {
  const opts = normalizeExecArgs(command, options, null);
  const inheritStderr = !opts.options.stdio;

  const ret = spawnSync(opts.file, opts.options);

  if (inheritStderr && ret.stderr)
    process.stderr.write(ret.stderr);

  const err = checkExecSyncError(ret, opts.args, command);

  if (err)
    throw err;

  return ret.stdout;
}

function checkExecSyncError(ret, args, cmd) {
  let err;
  if (ret.error) {
    err = ret.error;
  } else if (ret.status !== 0) {
    let msg = 'Command failed: ';
    msg += cmd || ArrayPrototypeJoin(args, ' ');
    if (ret.stderr && ret.stderr.length > 0)
      msg += `\n${ret.stderr.toString()}`;
    // eslint-disable-next-line no-restricted-syntax
    err = new Error(msg);
  }
  if (err) {
    ObjectAssign(err, ret);
  }
  return err;
}

ここで、execSync はコマンドを実行した後、checkExecSyncError に入って子プロセスの Exit Status Code が 0 であるかどうかを確認します。0 でない場合はコマンド実行エラーと見なし、例外をスローします。

問題はなさそうです。つまり、コマンドを実行する際にエラーが発生したということです。では、確認してみましょう。

このような Linux の Syscall 問題のトラブルシューティングに関するツール（この問題は Mac などの環境でも存在しますが、便宜上 Linux で再現しました）については、strace 以外にもっと成熟した便利なツールは見つかりません（eBPF に基づくものも可能ですが、正直言って自分で書くより strace の方が効果的です）。

コマンドを実行します。

sudo strace -t -f -p $PID -o error_trace.txt

tips: strace を使用する際は、-f オプションを利用して、トレースされたプロセスが作成した子プロセスをトレースできます。

コマンドを実行し、全ての syscall の呼び出しチェーンを取得しました。さあ、分析を始めましょう。

まず、最も重要な部分に目を向けます（ファイル全体が非常に長いため、約 4K 行ありますので、重要な部分だけを分析します）。

...
894259 13:21:23 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f12d9465a50) = 896940
...
896940 13:21:23 execve("/bin/sh", ["/bin/sh", "-c", "ps -Af | grep -E -c \"\\-\\-user-da"...], 0x4aae230 /* 40 vars */ <unfinished ...>
...
896940 13:21:24 <... wait4 resumed>[{WIFEXITED(s) && WEXITSTATUS(s) == 1}], 0, NULL) = 896942
896940 13:21:24 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=896942, si_uid=1000, si_status=1, si_utime=0, si_stime=0} ---
896940 13:21:24 rt_sigreturn({mask=[]}) = 896942
896940 13:21:24 exit_group(1)           = ?
896940 13:21:24 +++ exited with 1 +++

ここで、Node.js は直接 fork を使用して新しいプロセスを作成するのではなく、clone を使用して新しいプロセスを作成していることを知っておく必要があります。両者の違いについて詳しく説明するには、別の長文を書く必要があります（ここでは公式の説明を簡単に述べます）。

これらのシステムコールは、新しい（「子」）プロセスを作成しますが、fork (2) に似た方法で行われます。fork (2) と比較して、これらのシステムコールは、呼び出しプロセスと子プロセスの間で共有される実行コンテキストの部分をより正確に制御できます。たとえば、これらのシステムコールを使用すると、呼び出し元は、2 つのプロセスが仮想アドレス空間、ファイルディスクリプタのテーブル、およびシグナルハンドラのテーブルを共有するかどうかを制御できます。これらのシステムコールは、新しい子プロセスを別の名前空間に配置することも可能です。

簡潔に言えば、clone は fork に似た意味を提供しますが、clone を使用することで、開発者はプロセス / スレッド作成プロセスの詳細をより細かく制御できます。

さて、ここで 894259 という親プロセスが clone を使用して 896940 というプロセスを作成したことがわかります。実行中、896940 プロセスは execve システムコールを使用して sh（これは execSync のデフォルトの動作です）を通じて、私たちのコマンド ps -Af | grep -q -E -c "\\-\\-user-data-dir=\\.+App" を実行します。ここで、896940 が終了する際に、確かに 1 の exit code で終了したことがわかります。これは以前の分析と一致します。つまり、コマンドを実行する際にエラーが発生したということです。では、このエラーはどこにあるのでしょうか？

コマンドを分析してみましょう。一般的なシェルに精通している方は気づくかもしれませんが、私たちのコマンドにはパイプ操作子 | が実際に使用されています。正確には、この操作子が出現すると、前後の 2 つのコマンドはそれぞれ異なるプロセスで実行され、パイプを介して IPC が行われます。つまり、これらの 2 つのプロセスをすぐに特定できます。テキストを直接検索してみましょう。

...
896941 13:21:23 execve("/bin/ps", ["ps", "-Af"], 0x564c16f6ec38 /* 40 vars */) = 0
...
896942 13:21:23 execve("/bin/grep", ["grep", "-E", "-c", "\\-\\-user-data-dir=\\.*"], 0x564c16f6ecb0 /* 40 vars */ <unfinished ...>
...
896941 13:21:24 <... exit_group resumed>) = ?
896941 13:21:24 +++ exited with 0 +++
...
896942 13:21:24 exit_group(1)           = ?
896942 13:21:24 +++ exited with 1 +++

ここで、896942 すなわち grep を実行しているプロセスが直接 exit code 1 で終了したことがわかります。では、なぜでしょうか？grep の公式ドキュメントを見てみると、驚くべきことに、心臓が止まりそうです。

通常、選択された行が見つかった場合、終了ステータスは 0 であり、そうでない場合は 1 です。ただし、エラーが発生した場合は終了ステータスが 2 になります。ただし、-q または --quiet または --silent オプションが使用され、選択された行が見つかった場合はこの限りではありません。ただし、POSIX は grep、cmp、diff などのプログラムに対して、エラーが発生した場合の終了ステータスが 1 より大きいことを義務付けているため、移植性のために、厳密に 2 との等価性をテストするのではなく、この一般的な条件をテストするロジックを使用することをお勧めします。

もし grep がデータを見つけられなかった場合、プロセスは exit code 1 で終了します。もしマッチした場合は 0 で終了します。しかし、しかし、驚くべきことに、標準的な意味では exit code 1 の意味は Operation not permitted ではないのでしょうか？基本的な法則に従っていないのです！

まとめ#

実際、全体を通して見ると、2 つの理由をまとめることができます。

Node.js は POSIX 関連の API を抽象化して封装する際に、標準的な意味に従ってユーザーを保護しました。理論的には、これはアプリケーションの自己決定的な動作であるべきです。
grep が基本的な法則に従っていない。

正直なところ、これらの 2 つの側面のどちらがより厄介かを評価するのは難しいです。前述のように、子プロセスの exit code を処理することは理論的にはアプリケーションの自己決定的な動作であるべきですが、Node.js 自体が一層の封装を行い、ユーザーの心的負担を軽減する一方で、非標準的なシナリオに直面した場合には、かなりのリスクが伴うことになります。

さまざまなシナリオに応じてトレードオフを行うしかありません。

さて、この記事はここまでです。急遽書いたので、関連する参考文献を文中に挙げるのは面倒です。これで十分でしょう。水文の目標達成.jpg